Class org.broadinstitute.hellbender.tools.spark.pipelines.MarkDuplicatesSparkIntegrationTest

all > org.broadinstitute.hellbender.tools.spark.pipelines > MarkDuplicatesSparkIntegrationTest

152

tests

failures

ignored

59.761s

duration

100%

successful

Tests
Standard error

Tests

Test	Duration	Result
assertThatExpectedOutputUpdateToggleIsDisabled	0s	passed
testAssertAssumeUnsortedFilesAreQueryGroupedFiles	0.551s	passed
testAssertCorrectSortOrderMultipleBams	0.147s	passed
testAssertCorrectSortOrderMultipleBamsOverriding	0.504s	passed
testBulkFragmentsNoDuplicates	1.027s	passed
testBulkFragmentsWithDuplicates	2.061s	passed
testDifferentChromosomesInOppositeOrder	0.301s	passed
testDuplicateDetectionDataProviderWithMetrics[0](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.picard-2.15.0.sorted.chr1.1-1K.unmarkedDups.markDuplicate.metrics)	0.260s	passed
testDuplicateDetectionDataProviderWithMetrics[1](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.picard-2.15.0.sorted.optical_dupes.markDuplicate.metrics)	0.255s	passed
testDuplicateDetectionDataProviderWithMetrics[2](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.picard-2.15.0.sorted.inputSingleLibrarySolexa16404.metrics)	0.260s	passed
testFlowModeFlag	1.553s	passed
testHashCollisionHandling	1.045s	passed
testMDOrder[0](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.mdOrderBug.bam)	0.302s	passed
testMDOrder[1](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.mdOrderBug2.bam)	0.282s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[0](true, true, true)	0.296s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[1](true, false, true)	0.293s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[2](false, true, true)	0.322s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[3](true, true, false)	0.292s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[4](true, false, false)	0.312s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[5](false, true, false)	0.310s	passed
testMappedFragmentAndMappedPairFirstOfPairNonPrimary	0.297s	passed
testMappedFragmentAndMatePairFirstUnmapped	0.316s	passed
testMappedFragmentAndMatePairSecondUnmapped	0.304s	passed
testMappedPairAndMappedFragmentAndMatePairFirstUnmapped	0.301s	passed
testMappedPairAndMappedFragmentAndMatePairSecondUnmapped	0.342s	passed
testMappedPairAndMatePairFirstOppositeStrandSecondUnmapped	0.316s	passed
testMappedPairAndMatePairFirstUnmapped	0.293s	passed
testMappedPairAndMatePairSecondUnmapped	0.295s	passed
testMappedPairWithFirstEndSamePositionAndOther	0.294s	passed
testMappedPairWithSamePosition	0.292s	passed
testMappedPairWithSamePositionSameCigar	0.305s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[0]([Ljava.io.File;@104a4f2d, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]})	0.351s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[1]([Ljava.io.File;@36035e42, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.369s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[2]([Ljava.io.File;@675f0088, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.374s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[3]([Ljava.io.File;@4dc2b4ee, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.320s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[4]([Ljava.io.File;@55e83732, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.332s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[5]([Ljava.io.File;@42e56622, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.217s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[6]([Ljava.io.File;@5b8109bc, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.181s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[0]([Ljava.io.File;@ba311dd, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]})	0.344s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[1]([Ljava.io.File;@36cd9e10, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.375s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[2]([Ljava.io.File;@18fef9d8, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.393s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[3]([Ljava.io.File;@848af7b, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.342s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[4]([Ljava.io.File;@176fc92a, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.329s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[5]([Ljava.io.File;@4d2bb67b, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.227s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[6]([Ljava.io.File;@3022da3d, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.194s	passed
testMarkDuplicatesSparkIntegrationTestLocal[0]([Ljava.io.File;@79ee0514, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]})	0.335s	passed
testMarkDuplicatesSparkIntegrationTestLocal[1]([Ljava.io.File;@66740bab, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.337s	passed
testMarkDuplicatesSparkIntegrationTestLocal[2]([Ljava.io.File;@4ab29661, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.376s	passed
testMarkDuplicatesSparkIntegrationTestLocal[3]([Ljava.io.File;@59697b35, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.315s	passed
testMarkDuplicatesSparkIntegrationTestLocal[4]([Ljava.io.File;@6aa3d1a8, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.320s	passed
testMarkDuplicatesSparkIntegrationTestLocal[5]([Ljava.io.File;@2612258, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.169s	passed
testMarkDuplicatesSparkIntegrationTestLocal[6]([Ljava.io.File;@7acccac0, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.177s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[0]([Ljava.io.File;@2a2fc795, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]})	0.336s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[1]([Ljava.io.File;@656fb397, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.346s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[2]([Ljava.io.File;@3d896bad, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.354s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[3]([Ljava.io.File;@7722250b, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.312s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[4]([Ljava.io.File;@1c45ffca, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.324s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[5]([Ljava.io.File;@45369f6a, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.127s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[6]([Ljava.io.File;@1ca87209, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.134s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[0]([Ljava.io.File;@367cc3d1, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]})	0.335s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[1]([Ljava.io.File;@3dc55bc8, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.391s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[2]([Ljava.io.File;@4fa1e871, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.438s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[3]([Ljava.io.File;@ea92148, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.366s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[4]([Ljava.io.File;@94a80d9, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.341s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[5]([Ljava.io.File;@4db1ab0f, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.148s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[6]([Ljava.io.File;@7340a5e2, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.126s	passed
testMatePairFirstUnmapped	0.289s	passed
testMatePairSecondUnmapped	0.286s	passed
testNoReadGroupInRead	0.252s	passed
testNonExistantReadGroupInRead	0.234s	passed
testNullOpticalDuplicates	0.315s	passed
testOpticalDuplicateClusterOneEndSamePositionOneCluster	0.299s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicatesWithinPixelDistance	0.305s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834)	0.305s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756)	0.293s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756)	0.308s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756)	0.299s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756)	0.299s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756)	0.307s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144)	0.297s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756)	0.304s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756)	0.295s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756)	0.301s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756)	0.295s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756)	0.302s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756)	0.298s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756)	0.296s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756)	0.303s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756)	0.302s	passed
testOpticalDuplicateClusterSamePositionOneOpticalDuplicatesWithinPixelDistance	0.307s	passed
testOpticalDuplicateClustersAddingSecondEndFirstSameCoordinate	0.296s	passed
testOpticalDuplicateFinding	0.299s	passed
testOpticalDuplicateFindingPxelDistance	0.291s	passed
testOpticalDuplicatesAndPCRDuplicatesOrientationDifference	0.286s	passed
testOpticalDuplicatesDifferentReadGroups	0.296s	passed
testOpticalDuplicatesTheSameReadGroup	0.299s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834)	0.304s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756)	0.287s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756)	0.301s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756)	0.294s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756)	0.303s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756)	0.312s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144)	0.309s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756)	0.312s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756)	0.300s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756)	0.313s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756)	0.304s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756)	0.289s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756)	0.303s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756)	0.296s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756)	0.298s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756)	0.297s	passed
testPathologicalOrderingAtTheSamePosition	0.307s	passed
testReadSameStartPositionOrientationOverride	0.333s	passed
testReadsHaveSameStartPositionButDifferentChromosomeNonEquivalence	0.302s	passed
testSecondEndIsBeforeFirstInCoordinate	0.313s	passed
testSingleMappedFragment	0.309s	passed
testSingleMappedFragmentAndSingleMappedPair	0.295s	passed
testSingleMappedFragmentAndTwoMappedPairs	0.297s	passed
testSingleMappedPair	0.292s	passed
testSingleUnmappedFragment	0.287s	passed
testSingleUnmappedPair	0.295s	passed
testStackOverFlowPairSetSwap	0.289s	passed
testSupplementaryReadUnmappedMate	0.292s	passed
testThreeGroupsOnDifferentChromosomesOfThreeMappedPairs	0.297s	passed
testThreeMappedPairs	0.294s	passed
testThreeMappedPairsWithMatchingSecondMate	0.294s	passed
testTwoGroupsOnDifferentChromosomesOfThreeMappedPairs	0.287s	passed
testTwoGroupsOnDifferentChromosomesOfTwoFragments	0.285s	passed
testTwoGroupsOnDifferentChromosomesOfTwoMappedPairs	0.295s	passed
testTwoMappedFragments	0.293s	passed
testTwoMappedPairWithSamePosition	0.284s	passed
testTwoMappedPairWithSamePositionDifferentStrands	0.297s	passed
testTwoMappedPairWithSamePositionDifferentStrands2	0.295s	passed
testTwoMappedPairs	0.313s	passed
testTwoMappedPairsAndMappedSecondaryFragment	0.301s	passed
testTwoMappedPairsAndTerminalUnmappedFragment	0.289s	passed
testTwoMappedPairsAndTerminalUnmappedPair	0.300s	passed
testTwoMappedPairsMatesSoftClipped	0.291s	passed
testTwoMappedPairsWithOppositeOrientations	0.291s	passed
testTwoMappedPairsWithOppositeOrientationsNumberTwo	0.315s	passed
testTwoMappedPairsWithSoftClipping	0.304s	passed
testTwoMappedPairsWithSoftClippingBoth	0.301s	passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnly	0.319s	passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnlyNoMateCigar	0.295s	passed
testTwoMappedPairsWithSupplementaryReads[0](true, true, true)	0.298s	passed
testTwoMappedPairsWithSupplementaryReads[1](true, false, true)	0.289s	passed
testTwoMappedPairsWithSupplementaryReads[2](false, true, true)	0.291s	passed
testTwoMappedPairsWithSupplementaryReads[3](true, true, false)	0.294s	passed
testTwoMappedPairsWithSupplementaryReads[4](true, false, false)	0.286s	passed
testTwoMappedPairsWithSupplementaryReads[5](false, true, false)	0.286s	passed
testTwoUnmappedFragments	0.303s	passed

Standard error

[May 27, 2025 at 3:11:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:11:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:11:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:00 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
15:12:01.409 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:01.409 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v93cf621-SNAPSHOT
15:12:01.409 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:12:01.409 INFO  MarkDuplicatesSpark - Executing as root@07a40c7a9995 on Linux v6.11.0-1014-azure amd64
15:12:01.409 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
15:12:01.409 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 3:12:01 PM GMT
15:12:01.409 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:01.409 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:01.409 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
15:12:01.409 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
15:12:01.410 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
15:12:01.410 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:12:01.410 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:12:01.410 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:12:01.410 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:12:01.410 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:12:01.410 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:12:01.410 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:12:01.410 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:12:01.410 INFO  MarkDuplicatesSpark - Initializing engine
15:12:01.410 INFO  MarkDuplicatesSpark - Done initializing engine
15:12:01.410 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:12:01.413 INFO  MemoryStore - Block broadcast_1337 stored as values in memory (estimated size 305.5 KiB, free 1903.3 MiB)
15:12:01.419 INFO  MemoryStore - Block broadcast_1337_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1903.2 MiB)
15:12:01.419 INFO  BlockManagerInfo - Added broadcast_1337_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1918.9 MiB)
15:12:01.420 INFO  SparkContext - Created broadcast 1337 from newAPIHadoopFile at PathSplitSource.java:96
15:12:01.440 INFO  MemoryStore - Block broadcast_1338 stored as values in memory (estimated size 305.5 KiB, free 1902.9 MiB)
15:12:01.446 INFO  MemoryStore - Block broadcast_1338_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1902.9 MiB)
15:12:01.447 INFO  BlockManagerInfo - Added broadcast_1338_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1918.9 MiB)
15:12:01.447 INFO  SparkContext - Created broadcast 1338 from newAPIHadoopFile at PathSplitSource.java:96
15:12:01.480 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:12:01.480 INFO  FileInputFormat - Total input files to process : 1
15:12:01.481 INFO  DAGScheduler - Registering RDD 3396 (mapToPair at SparkUtils.java:161) as input to shuffle 97
15:12:01.481 INFO  DAGScheduler - Got job 413 (collect at SparkUtils.java:205) with 1 output partitions
15:12:01.481 INFO  DAGScheduler - Final stage: ResultStage 721 (collect at SparkUtils.java:205)
15:12:01.481 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 720)
15:12:01.481 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 720)
15:12:01.482 INFO  DAGScheduler - Submitting ShuffleMapStage 720 (MapPartitionsRDD[3396] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:01.499 INFO  MemoryStore - Block broadcast_1339 stored as values in memory (estimated size 459.2 KiB, free 1902.4 MiB)
15:12:01.502 INFO  MemoryStore - Block broadcast_1339_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1902.2 MiB)
15:12:01.502 INFO  BlockManagerInfo - Added broadcast_1339_piece0 in memory on localhost:36687 (size: 201.4 KiB, free: 1918.7 MiB)
15:12:01.502 INFO  SparkContext - Created broadcast 1339 from broadcast at DAGScheduler.scala:1580
15:12:01.503 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 720 (MapPartitionsRDD[3396] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:01.503 INFO  TaskSchedulerImpl - Adding task set 720.0 with 1 tasks resource profile 0
15:12:01.503 INFO  TaskSetManager - Starting task 0.0 in stage 720.0 (TID 650) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9650 bytes) 
15:12:01.504 INFO  Executor - Running task 0.0 in stage 720.0 (TID 650)
15:12:01.532 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam:0+1507
15:12:01.537 INFO  Executor - Finished task 0.0 in stage 720.0 (TID 650). 1148 bytes result sent to driver
15:12:01.537 INFO  TaskSetManager - Finished task 0.0 in stage 720.0 (TID 650) in 34 ms on localhost (executor driver) (1/1)
15:12:01.537 INFO  TaskSchedulerImpl - Removed TaskSet 720.0, whose tasks have all completed, from pool 
15:12:01.537 INFO  DAGScheduler - ShuffleMapStage 720 (mapToPair at SparkUtils.java:161) finished in 0.055 s
15:12:01.538 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.538 INFO  DAGScheduler - running: HashSet()
15:12:01.538 INFO  DAGScheduler - waiting: HashSet(ResultStage 721)
15:12:01.538 INFO  DAGScheduler - failed: HashSet()
15:12:01.538 INFO  DAGScheduler - Submitting ResultStage 721 (MapPartitionsRDD[3399] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:12:01.539 INFO  MemoryStore - Block broadcast_1340 stored as values in memory (estimated size 7.4 KiB, free 1902.2 MiB)
15:12:01.539 INFO  MemoryStore - Block broadcast_1340_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1902.2 MiB)
15:12:01.539 INFO  BlockManagerInfo - Added broadcast_1340_piece0 in memory on localhost:36687 (size: 4.1 KiB, free: 1918.7 MiB)
15:12:01.540 INFO  SparkContext - Created broadcast 1340 from broadcast at DAGScheduler.scala:1580
15:12:01.540 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 721 (MapPartitionsRDD[3399] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:12:01.540 INFO  TaskSchedulerImpl - Adding task set 721.0 with 1 tasks resource profile 0
15:12:01.541 INFO  TaskSetManager - Starting task 0.0 in stage 721.0 (TID 651) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:01.541 INFO  Executor - Running task 0.0 in stage 721.0 (TID 651)
15:12:01.542 INFO  ShuffleBlockFetcherIterator - Getting 1 (405.0 B) non-empty blocks including 1 (405.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.543 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.545 INFO  Executor - Finished task 0.0 in stage 721.0 (TID 651). 2238 bytes result sent to driver
15:12:01.545 INFO  TaskSetManager - Finished task 0.0 in stage 721.0 (TID 651) in 5 ms on localhost (executor driver) (1/1)
15:12:01.546 INFO  TaskSchedulerImpl - Removed TaskSet 721.0, whose tasks have all completed, from pool 
15:12:01.546 INFO  DAGScheduler - ResultStage 721 (collect at SparkUtils.java:205) finished in 0.008 s
15:12:01.546 INFO  DAGScheduler - Job 413 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:01.546 INFO  TaskSchedulerImpl - Killing all running tasks in stage 721: Stage finished
15:12:01.546 INFO  DAGScheduler - Job 413 finished: collect at SparkUtils.java:205, took 0.066511 s
15:12:01.552 INFO  MemoryStore - Block broadcast_1341 stored as values in memory (estimated size 1632.0 B, free 1902.2 MiB)
15:12:01.552 INFO  MemoryStore - Block broadcast_1341_piece0 stored as bytes in memory (estimated size 145.0 B, free 1902.2 MiB)
15:12:01.553 INFO  BlockManagerInfo - Added broadcast_1341_piece0 in memory on localhost:36687 (size: 145.0 B, free: 1918.7 MiB)
15:12:01.553 INFO  SparkContext - Created broadcast 1341 from broadcast at MarkDuplicatesSparkUtils.java:126
15:12:01.553 INFO  MemoryStore - Block broadcast_1342 stored as values in memory (estimated size 304.0 B, free 1902.2 MiB)
15:12:01.553 INFO  MemoryStore - Block broadcast_1342_piece0 stored as bytes in memory (estimated size 37.0 B, free 1902.2 MiB)
15:12:01.554 INFO  BlockManagerInfo - Added broadcast_1342_piece0 in memory on localhost:36687 (size: 37.0 B, free: 1918.7 MiB)
15:12:01.554 INFO  SparkContext - Created broadcast 1342 from broadcast at MarkDuplicatesSparkUtils.java:127
15:12:01.566 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:12:01.566 INFO  DAGScheduler - Registering RDD 3408 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 100
15:12:01.567 INFO  DAGScheduler - Registering RDD 3412 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 99
15:12:01.567 INFO  DAGScheduler - Registering RDD 3416 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 98
15:12:01.567 INFO  DAGScheduler - Got job 414 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:12:01.567 INFO  DAGScheduler - Final stage: ResultStage 726 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:12:01.567 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 725)
15:12:01.567 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 725)
15:12:01.568 INFO  DAGScheduler - Submitting ShuffleMapStage 723 (MapPartitionsRDD[3408] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:12:01.568 INFO  MemoryStore - Block broadcast_1343 stored as values in memory (estimated size 24.2 KiB, free 1902.2 MiB)
15:12:01.569 INFO  MemoryStore - Block broadcast_1343_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1902.2 MiB)
15:12:01.569 INFO  BlockManagerInfo - Added broadcast_1343_piece0 in memory on localhost:36687 (size: 12.6 KiB, free: 1918.6 MiB)
15:12:01.569 INFO  SparkContext - Created broadcast 1343 from broadcast at DAGScheduler.scala:1580
15:12:01.570 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 723 (MapPartitionsRDD[3408] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:12:01.570 INFO  TaskSchedulerImpl - Adding task set 723.0 with 1 tasks resource profile 0
15:12:01.571 INFO  TaskSetManager - Starting task 0.0 in stage 723.0 (TID 652) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
15:12:01.571 INFO  Executor - Running task 0.0 in stage 723.0 (TID 652)
15:12:01.572 INFO  ShuffleBlockFetcherIterator - Getting 1 (405.0 B) non-empty blocks including 1 (405.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.573 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.576 INFO  Executor - Finished task 0.0 in stage 723.0 (TID 652). 1922 bytes result sent to driver
15:12:01.576 INFO  TaskSetManager - Finished task 0.0 in stage 723.0 (TID 652) in 6 ms on localhost (executor driver) (1/1)
15:12:01.576 INFO  TaskSchedulerImpl - Removed TaskSet 723.0, whose tasks have all completed, from pool 
15:12:01.576 INFO  DAGScheduler - ShuffleMapStage 723 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
15:12:01.576 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.576 INFO  DAGScheduler - running: HashSet()
15:12:01.576 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 724, ShuffleMapStage 725, ResultStage 726)
15:12:01.576 INFO  DAGScheduler - failed: HashSet()
15:12:01.577 INFO  DAGScheduler - Submitting ShuffleMapStage 724 (MapPartitionsRDD[3412] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:12:01.577 INFO  MemoryStore - Block broadcast_1344 stored as values in memory (estimated size 28.3 KiB, free 1902.1 MiB)
15:12:01.578 INFO  MemoryStore - Block broadcast_1344_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1902.1 MiB)
15:12:01.578 INFO  BlockManagerInfo - Added broadcast_1344_piece0 in memory on localhost:36687 (size: 14.8 KiB, free: 1918.6 MiB)
15:12:01.578 INFO  SparkContext - Created broadcast 1344 from broadcast at DAGScheduler.scala:1580
15:12:01.579 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 724 (MapPartitionsRDD[3412] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:12:01.579 INFO  TaskSchedulerImpl - Adding task set 724.0 with 1 tasks resource profile 0
15:12:01.579 INFO  TaskSetManager - Starting task 0.0 in stage 724.0 (TID 653) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
15:12:01.579 INFO  Executor - Running task 0.0 in stage 724.0 (TID 653)
15:12:01.581 INFO  ShuffleBlockFetcherIterator - Getting 1 (129.0 B) non-empty blocks including 1 (129.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.581 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.584 INFO  Executor - Finished task 0.0 in stage 724.0 (TID 653). 1922 bytes result sent to driver
15:12:01.584 INFO  TaskSetManager - Finished task 0.0 in stage 724.0 (TID 653) in 5 ms on localhost (executor driver) (1/1)
15:12:01.584 INFO  TaskSchedulerImpl - Removed TaskSet 724.0, whose tasks have all completed, from pool 
15:12:01.584 INFO  DAGScheduler - ShuffleMapStage 724 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
15:12:01.584 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.584 INFO  DAGScheduler - running: HashSet()
15:12:01.585 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 725, ResultStage 726)
15:12:01.585 INFO  DAGScheduler - failed: HashSet()
15:12:01.585 INFO  DAGScheduler - Submitting ShuffleMapStage 725 (MapPartitionsRDD[3416] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:12:01.585 INFO  MemoryStore - Block broadcast_1345 stored as values in memory (estimated size 19.0 KiB, free 1902.1 MiB)
15:12:01.586 INFO  MemoryStore - Block broadcast_1345_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1902.1 MiB)
15:12:01.586 INFO  BlockManagerInfo - Added broadcast_1345_piece0 in memory on localhost:36687 (size: 9.7 KiB, free: 1918.6 MiB)
15:12:01.586 INFO  SparkContext - Created broadcast 1345 from broadcast at DAGScheduler.scala:1580
15:12:01.586 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 725 (MapPartitionsRDD[3416] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:12:01.586 INFO  TaskSchedulerImpl - Adding task set 725.0 with 1 tasks resource profile 0
15:12:01.587 INFO  TaskSetManager - Starting task 0.0 in stage 725.0 (TID 654) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:01.587 INFO  Executor - Running task 0.0 in stage 725.0 (TID 654)
15:12:01.588 INFO  ShuffleBlockFetcherIterator - Getting 1 (405.0 B) non-empty blocks including 1 (405.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.588 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.590 INFO  ShuffleBlockFetcherIterator - Getting 1 (117.0 B) non-empty blocks including 1 (117.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.590 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.591 INFO  Executor - Finished task 0.0 in stage 725.0 (TID 654). 1879 bytes result sent to driver
15:12:01.591 INFO  TaskSetManager - Finished task 0.0 in stage 725.0 (TID 654) in 4 ms on localhost (executor driver) (1/1)
15:12:01.591 INFO  TaskSchedulerImpl - Removed TaskSet 725.0, whose tasks have all completed, from pool 
15:12:01.592 INFO  DAGScheduler - ShuffleMapStage 725 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.007 s
15:12:01.592 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.592 INFO  DAGScheduler - running: HashSet()
15:12:01.592 INFO  DAGScheduler - waiting: HashSet(ResultStage 726)
15:12:01.592 INFO  DAGScheduler - failed: HashSet()
15:12:01.592 INFO  DAGScheduler - Submitting ResultStage 726 (MapPartitionsRDD[3418] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:12:01.592 INFO  MemoryStore - Block broadcast_1346 stored as values in memory (estimated size 20.2 KiB, free 1902.1 MiB)
15:12:01.593 INFO  MemoryStore - Block broadcast_1346_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1902.1 MiB)
15:12:01.593 INFO  BlockManagerInfo - Added broadcast_1346_piece0 in memory on localhost:36687 (size: 10.6 KiB, free: 1918.6 MiB)
15:12:01.593 INFO  SparkContext - Created broadcast 1346 from broadcast at DAGScheduler.scala:1580
15:12:01.594 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 726 (MapPartitionsRDD[3418] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:12:01.594 INFO  TaskSchedulerImpl - Adding task set 726.0 with 1 tasks resource profile 0
15:12:01.594 INFO  TaskSetManager - Starting task 0.0 in stage 726.0 (TID 655) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:01.594 INFO  Executor - Running task 0.0 in stage 726.0 (TID 655)
15:12:01.595 INFO  ShuffleBlockFetcherIterator - Getting 1 (117.0 B) non-empty blocks including 1 (117.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.595 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.597 INFO  Executor - Finished task 0.0 in stage 726.0 (TID 655). 1901 bytes result sent to driver
15:12:01.597 INFO  TaskSetManager - Finished task 0.0 in stage 726.0 (TID 655) in 3 ms on localhost (executor driver) (1/1)
15:12:01.597 INFO  TaskSchedulerImpl - Removed TaskSet 726.0, whose tasks have all completed, from pool 
15:12:01.597 INFO  DAGScheduler - ResultStage 726 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
15:12:01.598 INFO  DAGScheduler - Job 414 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:01.598 INFO  TaskSchedulerImpl - Killing all running tasks in stage 726: Stage finished
15:12:01.598 INFO  DAGScheduler - Job 414 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.031819 s
15:12:01.607 INFO  MemoryStore - Block broadcast_1347 stored as values in memory (estimated size 20.3 KiB, free 1902.0 MiB)
15:12:01.608 INFO  MemoryStore - Block broadcast_1347_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1902.0 MiB)
15:12:01.608 INFO  BlockManagerInfo - Added broadcast_1347_piece0 in memory on localhost:36687 (size: 1850.0 B, free: 1918.6 MiB)
15:12:01.608 INFO  SparkContext - Created broadcast 1347 from broadcast at ReadsSparkSink.java:133
15:12:01.609 INFO  MemoryStore - Block broadcast_1348 stored as values in memory (estimated size 20.4 KiB, free 1902.0 MiB)
15:12:01.609 INFO  MemoryStore - Block broadcast_1348_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1902.0 MiB)
15:12:01.610 INFO  BlockManagerInfo - Added broadcast_1348_piece0 in memory on localhost:36687 (size: 1850.0 B, free: 1918.6 MiB)
15:12:01.610 INFO  SparkContext - Created broadcast 1348 from broadcast at BamSink.java:76
15:12:01.611 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:12:01.611 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:01.611 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:01.622 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:12:01.623 INFO  DAGScheduler - Registering RDD 3420 (mapToPair at SparkUtils.java:161) as input to shuffle 101
15:12:01.623 INFO  DAGScheduler - Got job 415 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:12:01.623 INFO  DAGScheduler - Final stage: ResultStage 731 (runJob at SparkHadoopWriter.scala:83)
15:12:01.623 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 730)
15:12:01.623 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 730)
15:12:01.623 INFO  DAGScheduler - Submitting ShuffleMapStage 730 (MapPartitionsRDD[3420] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:01.624 INFO  MemoryStore - Block broadcast_1349 stored as values in memory (estimated size 18.1 KiB, free 1902.0 MiB)
15:12:01.624 INFO  MemoryStore - Block broadcast_1349_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1902.0 MiB)
15:12:01.625 INFO  BlockManagerInfo - Added broadcast_1349_piece0 in memory on localhost:36687 (size: 9.5 KiB, free: 1918.6 MiB)
15:12:01.625 INFO  SparkContext - Created broadcast 1349 from broadcast at DAGScheduler.scala:1580
15:12:01.625 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 730 (MapPartitionsRDD[3420] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:01.625 INFO  TaskSchedulerImpl - Adding task set 730.0 with 1 tasks resource profile 0
15:12:01.625 INFO  TaskSetManager - Starting task 0.0 in stage 730.0 (TID 656) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:01.626 INFO  Executor - Running task 0.0 in stage 730.0 (TID 656)
15:12:01.627 INFO  ShuffleBlockFetcherIterator - Getting 1 (405.0 B) non-empty blocks including 1 (405.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.627 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.629 INFO  ShuffleBlockFetcherIterator - Getting 1 (117.0 B) non-empty blocks including 1 (117.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.629 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.631 INFO  Executor - Finished task 0.0 in stage 730.0 (TID 656). 1922 bytes result sent to driver
15:12:01.631 INFO  TaskSetManager - Finished task 0.0 in stage 730.0 (TID 656) in 6 ms on localhost (executor driver) (1/1)
15:12:01.631 INFO  TaskSchedulerImpl - Removed TaskSet 730.0, whose tasks have all completed, from pool 
15:12:01.631 INFO  DAGScheduler - ShuffleMapStage 730 (mapToPair at SparkUtils.java:161) finished in 0.008 s
15:12:01.631 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.631 INFO  DAGScheduler - running: HashSet()
15:12:01.631 INFO  DAGScheduler - waiting: HashSet(ResultStage 731)
15:12:01.631 INFO  DAGScheduler - failed: HashSet()
15:12:01.632 INFO  DAGScheduler - Submitting ResultStage 731 (MapPartitionsRDD[3425] at mapToPair at BamSink.java:91), which has no missing parents
15:12:01.638 INFO  MemoryStore - Block broadcast_1350 stored as values in memory (estimated size 163.3 KiB, free 1901.8 MiB)
15:12:01.639 INFO  MemoryStore - Block broadcast_1350_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1901.8 MiB)
15:12:01.639 INFO  BlockManagerInfo - Added broadcast_1350_piece0 in memory on localhost:36687 (size: 73.4 KiB, free: 1918.5 MiB)
15:12:01.639 INFO  SparkContext - Created broadcast 1350 from broadcast at DAGScheduler.scala:1580
15:12:01.639 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 731 (MapPartitionsRDD[3425] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
15:12:01.639 INFO  TaskSchedulerImpl - Adding task set 731.0 with 1 tasks resource profile 0
15:12:01.640 INFO  TaskSetManager - Starting task 0.0 in stage 731.0 (TID 657) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:01.640 INFO  Executor - Running task 0.0 in stage 731.0 (TID 657)
15:12:01.643 INFO  ShuffleBlockFetcherIterator - Getting 1 (405.0 B) non-empty blocks including 1 (405.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.643 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.645 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:12:01.645 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:01.645 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:01.645 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:12:01.645 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:01.645 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:01.655 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271512013921407341984746891_3425_r_000000_0' to file:/tmp/local14191972300622296671/markdups16322140848730063259.bam.parts/_temporary/0/task_202505271512013921407341984746891_3425_r_000000
15:12:01.655 INFO  SparkHadoopMapRedUtil - attempt_202505271512013921407341984746891_3425_r_000000_0: Committed. Elapsed time: 0 ms.
15:12:01.656 INFO  Executor - Finished task 0.0 in stage 731.0 (TID 657). 1858 bytes result sent to driver
15:12:01.656 INFO  TaskSetManager - Finished task 0.0 in stage 731.0 (TID 657) in 16 ms on localhost (executor driver) (1/1)
15:12:01.656 INFO  TaskSchedulerImpl - Removed TaskSet 731.0, whose tasks have all completed, from pool 
15:12:01.656 INFO  DAGScheduler - ResultStage 731 (runJob at SparkHadoopWriter.scala:83) finished in 0.024 s
15:12:01.656 INFO  DAGScheduler - Job 415 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:01.656 INFO  TaskSchedulerImpl - Killing all running tasks in stage 731: Stage finished
15:12:01.656 INFO  DAGScheduler - Job 415 finished: runJob at SparkHadoopWriter.scala:83, took 0.033946 s
15:12:01.657 INFO  SparkHadoopWriter - Start to commit write Job job_202505271512013921407341984746891_3425.
15:12:01.659 INFO  SparkHadoopWriter - Write Job job_202505271512013921407341984746891_3425 committed. Elapsed time: 2 ms.
15:12:01.666 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local14191972300622296671/markdups16322140848730063259.bam
15:12:01.668 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local14191972300622296671/markdups16322140848730063259.bam done
15:12:01.669 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local14191972300622296671/markdups16322140848730063259.bam.parts/ to /tmp/local14191972300622296671/markdups16322140848730063259.bam.sbi
15:12:01.671 INFO  IndexFileMerger - Done merging .sbi files
15:12:01.671 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local14191972300622296671/markdups16322140848730063259.bam.parts/ to /tmp/local14191972300622296671/markdups16322140848730063259.bam.bai
15:12:01.674 INFO  IndexFileMerger - Done merging .bai files
15:12:01.674 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 3:12:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
15:12:01.690 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:01.690 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v93cf621-SNAPSHOT
15:12:01.690 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:12:01.690 INFO  MarkDuplicatesSpark - Executing as root@07a40c7a9995 on Linux v6.11.0-1014-azure amd64
15:12:01.690 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
15:12:01.690 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 3:12:01 PM GMT
15:12:01.690 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:01.690 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:01.691 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
15:12:01.691 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
15:12:01.691 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
15:12:01.691 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:12:01.691 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:12:01.691 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:12:01.691 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:12:01.691 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:12:01.691 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:12:01.691 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:12:01.691 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:12:01.691 INFO  MarkDuplicatesSpark - Initializing engine
15:12:01.691 INFO  MarkDuplicatesSpark - Done initializing engine
15:12:01.691 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:12:01.693 INFO  MemoryStore - Block broadcast_1351 stored as values in memory (estimated size 305.5 KiB, free 1901.5 MiB)
15:12:01.700 INFO  MemoryStore - Block broadcast_1351_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1901.4 MiB)
15:12:01.700 INFO  BlockManagerInfo - Added broadcast_1351_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1918.5 MiB)
15:12:01.700 INFO  SparkContext - Created broadcast 1351 from newAPIHadoopFile at PathSplitSource.java:96
15:12:01.720 INFO  MemoryStore - Block broadcast_1352 stored as values in memory (estimated size 305.5 KiB, free 1901.1 MiB)
15:12:01.726 INFO  MemoryStore - Block broadcast_1352_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1901.0 MiB)
15:12:01.726 INFO  BlockManagerInfo - Added broadcast_1352_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1918.4 MiB)
15:12:01.727 INFO  SparkContext - Created broadcast 1352 from newAPIHadoopFile at PathSplitSource.java:96
15:12:01.758 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:12:01.759 INFO  FileInputFormat - Total input files to process : 1
15:12:01.759 INFO  DAGScheduler - Registering RDD 3439 (mapToPair at SparkUtils.java:161) as input to shuffle 102
15:12:01.759 INFO  DAGScheduler - Got job 416 (collect at SparkUtils.java:205) with 1 output partitions
15:12:01.759 INFO  DAGScheduler - Final stage: ResultStage 733 (collect at SparkUtils.java:205)
15:12:01.759 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 732)
15:12:01.759 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 732)
15:12:01.759 INFO  DAGScheduler - Submitting ShuffleMapStage 732 (MapPartitionsRDD[3439] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:01.777 INFO  MemoryStore - Block broadcast_1353 stored as values in memory (estimated size 459.2 KiB, free 1900.6 MiB)
15:12:01.779 INFO  MemoryStore - Block broadcast_1353_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1900.4 MiB)
15:12:01.780 INFO  BlockManagerInfo - Added broadcast_1353_piece0 in memory on localhost:36687 (size: 201.4 KiB, free: 1918.2 MiB)
15:12:01.780 INFO  SparkContext - Created broadcast 1353 from broadcast at DAGScheduler.scala:1580
15:12:01.780 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 732 (MapPartitionsRDD[3439] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:01.780 INFO  TaskSchedulerImpl - Adding task set 732.0 with 1 tasks resource profile 0
15:12:01.780 INFO  TaskSetManager - Starting task 0.0 in stage 732.0 (TID 658) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9651 bytes) 
15:12:01.780 INFO  Executor - Running task 0.0 in stage 732.0 (TID 658)
15:12:01.808 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam:0+1856
15:12:01.812 INFO  Executor - Finished task 0.0 in stage 732.0 (TID 658). 1148 bytes result sent to driver
15:12:01.813 INFO  TaskSetManager - Finished task 0.0 in stage 732.0 (TID 658) in 33 ms on localhost (executor driver) (1/1)
15:12:01.813 INFO  TaskSchedulerImpl - Removed TaskSet 732.0, whose tasks have all completed, from pool 
15:12:01.813 INFO  DAGScheduler - ShuffleMapStage 732 (mapToPair at SparkUtils.java:161) finished in 0.053 s
15:12:01.813 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.813 INFO  DAGScheduler - running: HashSet()
15:12:01.813 INFO  DAGScheduler - waiting: HashSet(ResultStage 733)
15:12:01.813 INFO  DAGScheduler - failed: HashSet()
15:12:01.813 INFO  DAGScheduler - Submitting ResultStage 733 (MapPartitionsRDD[3442] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:12:01.814 INFO  MemoryStore - Block broadcast_1354 stored as values in memory (estimated size 7.4 KiB, free 1900.4 MiB)
15:12:01.814 INFO  MemoryStore - Block broadcast_1354_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1900.4 MiB)
15:12:01.814 INFO  BlockManagerInfo - Added broadcast_1354_piece0 in memory on localhost:36687 (size: 4.1 KiB, free: 1918.2 MiB)
15:12:01.815 INFO  SparkContext - Created broadcast 1354 from broadcast at DAGScheduler.scala:1580
15:12:01.815 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 733 (MapPartitionsRDD[3442] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:12:01.815 INFO  TaskSchedulerImpl - Adding task set 733.0 with 1 tasks resource profile 0
15:12:01.815 INFO  TaskSetManager - Starting task 0.0 in stage 733.0 (TID 659) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:01.815 INFO  Executor - Running task 0.0 in stage 733.0 (TID 659)
15:12:01.816 INFO  ShuffleBlockFetcherIterator - Getting 1 (868.0 B) non-empty blocks including 1 (868.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.816 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.818 INFO  Executor - Finished task 0.0 in stage 733.0 (TID 659). 2495 bytes result sent to driver
15:12:01.818 INFO  TaskSetManager - Finished task 0.0 in stage 733.0 (TID 659) in 3 ms on localhost (executor driver) (1/1)
15:12:01.818 INFO  TaskSchedulerImpl - Removed TaskSet 733.0, whose tasks have all completed, from pool 
15:12:01.818 INFO  DAGScheduler - ResultStage 733 (collect at SparkUtils.java:205) finished in 0.004 s
15:12:01.819 INFO  DAGScheduler - Job 416 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:01.819 INFO  TaskSchedulerImpl - Killing all running tasks in stage 733: Stage finished
15:12:01.819 INFO  DAGScheduler - Job 416 finished: collect at SparkUtils.java:205, took 0.060595 s
15:12:01.823 INFO  MemoryStore - Block broadcast_1355 stored as values in memory (estimated size 1632.0 B, free 1900.4 MiB)
15:12:01.823 INFO  MemoryStore - Block broadcast_1355_piece0 stored as bytes in memory (estimated size 145.0 B, free 1900.4 MiB)
15:12:01.823 INFO  BlockManagerInfo - Added broadcast_1355_piece0 in memory on localhost:36687 (size: 145.0 B, free: 1918.2 MiB)
15:12:01.824 INFO  SparkContext - Created broadcast 1355 from broadcast at MarkDuplicatesSparkUtils.java:126
15:12:01.824 INFO  MemoryStore - Block broadcast_1356 stored as values in memory (estimated size 304.0 B, free 1900.4 MiB)
15:12:01.824 INFO  MemoryStore - Block broadcast_1356_piece0 stored as bytes in memory (estimated size 37.0 B, free 1900.4 MiB)
15:12:01.824 INFO  BlockManagerInfo - Added broadcast_1356_piece0 in memory on localhost:36687 (size: 37.0 B, free: 1918.2 MiB)
15:12:01.825 INFO  SparkContext - Created broadcast 1356 from broadcast at MarkDuplicatesSparkUtils.java:127
15:12:01.836 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:12:01.837 INFO  DAGScheduler - Registering RDD 3451 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 105
15:12:01.837 INFO  DAGScheduler - Registering RDD 3455 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 104
15:12:01.837 INFO  DAGScheduler - Registering RDD 3459 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 103
15:12:01.837 INFO  DAGScheduler - Got job 417 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:12:01.837 INFO  DAGScheduler - Final stage: ResultStage 738 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:12:01.837 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 737)
15:12:01.838 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 737)
15:12:01.838 INFO  DAGScheduler - Submitting ShuffleMapStage 735 (MapPartitionsRDD[3451] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:12:01.839 INFO  MemoryStore - Block broadcast_1357 stored as values in memory (estimated size 24.2 KiB, free 1900.4 MiB)
15:12:01.839 INFO  MemoryStore - Block broadcast_1357_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1900.3 MiB)
15:12:01.839 INFO  BlockManagerInfo - Added broadcast_1357_piece0 in memory on localhost:36687 (size: 12.6 KiB, free: 1918.2 MiB)
15:12:01.840 INFO  SparkContext - Created broadcast 1357 from broadcast at DAGScheduler.scala:1580
15:12:01.840 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 735 (MapPartitionsRDD[3451] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:12:01.840 INFO  TaskSchedulerImpl - Adding task set 735.0 with 1 tasks resource profile 0
15:12:01.840 INFO  TaskSetManager - Starting task 0.0 in stage 735.0 (TID 660) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
15:12:01.841 INFO  Executor - Running task 0.0 in stage 735.0 (TID 660)
15:12:01.842 INFO  ShuffleBlockFetcherIterator - Getting 1 (868.0 B) non-empty blocks including 1 (868.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.842 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.845 INFO  Executor - Finished task 0.0 in stage 735.0 (TID 660). 1922 bytes result sent to driver
15:12:01.845 INFO  TaskSetManager - Finished task 0.0 in stage 735.0 (TID 660) in 5 ms on localhost (executor driver) (1/1)
15:12:01.845 INFO  TaskSchedulerImpl - Removed TaskSet 735.0, whose tasks have all completed, from pool 
15:12:01.846 INFO  DAGScheduler - ShuffleMapStage 735 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
15:12:01.846 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.846 INFO  DAGScheduler - running: HashSet()
15:12:01.846 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 736, ShuffleMapStage 737, ResultStage 738)
15:12:01.846 INFO  DAGScheduler - failed: HashSet()
15:12:01.846 INFO  DAGScheduler - Submitting ShuffleMapStage 736 (MapPartitionsRDD[3455] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:12:01.846 INFO  MemoryStore - Block broadcast_1358 stored as values in memory (estimated size 28.3 KiB, free 1900.3 MiB)
15:12:01.847 INFO  MemoryStore - Block broadcast_1358_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1900.3 MiB)
15:12:01.847 INFO  BlockManagerInfo - Added broadcast_1358_piece0 in memory on localhost:36687 (size: 14.8 KiB, free: 1918.2 MiB)
15:12:01.847 INFO  SparkContext - Created broadcast 1358 from broadcast at DAGScheduler.scala:1580
15:12:01.847 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 736 (MapPartitionsRDD[3455] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:12:01.848 INFO  TaskSchedulerImpl - Adding task set 736.0 with 1 tasks resource profile 0
15:12:01.848 INFO  TaskSetManager - Starting task 0.0 in stage 736.0 (TID 661) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
15:12:01.848 INFO  Executor - Running task 0.0 in stage 736.0 (TID 661)
15:12:01.850 INFO  ShuffleBlockFetcherIterator - Getting 1 (142.0 B) non-empty blocks including 1 (142.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.850 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.854 INFO  Executor - Finished task 0.0 in stage 736.0 (TID 661). 1922 bytes result sent to driver
15:12:01.854 INFO  TaskSetManager - Finished task 0.0 in stage 736.0 (TID 661) in 6 ms on localhost (executor driver) (1/1)
15:12:01.855 INFO  TaskSchedulerImpl - Removed TaskSet 736.0, whose tasks have all completed, from pool 
15:12:01.855 INFO  DAGScheduler - ShuffleMapStage 736 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
15:12:01.855 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.855 INFO  DAGScheduler - running: HashSet()
15:12:01.855 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 737, ResultStage 738)
15:12:01.855 INFO  DAGScheduler - failed: HashSet()
15:12:01.855 INFO  DAGScheduler - Submitting ShuffleMapStage 737 (MapPartitionsRDD[3459] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:12:01.856 INFO  MemoryStore - Block broadcast_1359 stored as values in memory (estimated size 19.0 KiB, free 1900.3 MiB)
15:12:01.856 INFO  MemoryStore - Block broadcast_1359_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1900.3 MiB)
15:12:01.856 INFO  BlockManagerInfo - Added broadcast_1359_piece0 in memory on localhost:36687 (size: 9.7 KiB, free: 1918.2 MiB)
15:12:01.857 INFO  SparkContext - Created broadcast 1359 from broadcast at DAGScheduler.scala:1580
15:12:01.857 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 737 (MapPartitionsRDD[3459] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:12:01.857 INFO  TaskSchedulerImpl - Adding task set 737.0 with 1 tasks resource profile 0
15:12:01.857 INFO  TaskSetManager - Starting task 0.0 in stage 737.0 (TID 662) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:01.857 INFO  Executor - Running task 0.0 in stage 737.0 (TID 662)
15:12:01.859 INFO  ShuffleBlockFetcherIterator - Getting 1 (868.0 B) non-empty blocks including 1 (868.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.859 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.861 INFO  ShuffleBlockFetcherIterator - Getting 1 (117.0 B) non-empty blocks including 1 (117.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.861 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.863 INFO  Executor - Finished task 0.0 in stage 737.0 (TID 662). 1922 bytes result sent to driver
15:12:01.863 INFO  TaskSetManager - Finished task 0.0 in stage 737.0 (TID 662) in 6 ms on localhost (executor driver) (1/1)
15:12:01.863 INFO  TaskSchedulerImpl - Removed TaskSet 737.0, whose tasks have all completed, from pool 
15:12:01.863 INFO  DAGScheduler - ShuffleMapStage 737 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
15:12:01.863 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.863 INFO  DAGScheduler - running: HashSet()
15:12:01.863 INFO  DAGScheduler - waiting: HashSet(ResultStage 738)
15:12:01.863 INFO  DAGScheduler - failed: HashSet()
15:12:01.863 INFO  DAGScheduler - Submitting ResultStage 738 (MapPartitionsRDD[3461] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:12:01.864 INFO  MemoryStore - Block broadcast_1360 stored as values in memory (estimated size 20.2 KiB, free 1900.3 MiB)
15:12:01.865 INFO  MemoryStore - Block broadcast_1360_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1900.2 MiB)
15:12:01.865 INFO  BlockManagerInfo - Added broadcast_1360_piece0 in memory on localhost:36687 (size: 10.6 KiB, free: 1918.1 MiB)
15:12:01.865 INFO  SparkContext - Created broadcast 1360 from broadcast at DAGScheduler.scala:1580
15:12:01.865 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 738 (MapPartitionsRDD[3461] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:12:01.865 INFO  TaskSchedulerImpl - Adding task set 738.0 with 1 tasks resource profile 0
15:12:01.865 INFO  TaskSetManager - Starting task 0.0 in stage 738.0 (TID 663) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:01.866 INFO  Executor - Running task 0.0 in stage 738.0 (TID 663)
15:12:01.867 INFO  ShuffleBlockFetcherIterator - Getting 1 (142.0 B) non-empty blocks including 1 (142.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.867 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.869 INFO  Executor - Finished task 0.0 in stage 738.0 (TID 663). 2053 bytes result sent to driver
15:12:01.869 INFO  TaskSetManager - Finished task 0.0 in stage 738.0 (TID 663) in 4 ms on localhost (executor driver) (1/1)
15:12:01.869 INFO  TaskSchedulerImpl - Removed TaskSet 738.0, whose tasks have all completed, from pool 
15:12:01.869 INFO  DAGScheduler - ResultStage 738 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
15:12:01.870 INFO  DAGScheduler - Job 417 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:01.870 INFO  TaskSchedulerImpl - Killing all running tasks in stage 738: Stage finished
15:12:01.870 INFO  DAGScheduler - Job 417 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.033353 s
15:12:01.879 INFO  MemoryStore - Block broadcast_1361 stored as values in memory (estimated size 20.3 KiB, free 1900.2 MiB)
15:12:01.880 INFO  MemoryStore - Block broadcast_1361_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.2 MiB)
15:12:01.880 INFO  BlockManagerInfo - Added broadcast_1361_piece0 in memory on localhost:36687 (size: 1850.0 B, free: 1918.1 MiB)
15:12:01.880 INFO  SparkContext - Created broadcast 1361 from broadcast at ReadsSparkSink.java:133
15:12:01.881 INFO  MemoryStore - Block broadcast_1362 stored as values in memory (estimated size 20.4 KiB, free 1900.2 MiB)
15:12:01.881 INFO  MemoryStore - Block broadcast_1362_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.2 MiB)
15:12:01.881 INFO  BlockManagerInfo - Added broadcast_1362_piece0 in memory on localhost:36687 (size: 1850.0 B, free: 1918.1 MiB)
15:12:01.882 INFO  SparkContext - Created broadcast 1362 from broadcast at BamSink.java:76
15:12:01.883 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:12:01.883 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:01.883 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:01.899 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:12:01.900 INFO  DAGScheduler - Registering RDD 3463 (mapToPair at SparkUtils.java:161) as input to shuffle 106
15:12:01.900 INFO  DAGScheduler - Got job 418 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:12:01.900 INFO  DAGScheduler - Final stage: ResultStage 743 (runJob at SparkHadoopWriter.scala:83)
15:12:01.900 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 742)
15:12:01.900 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 742)
15:12:01.900 INFO  DAGScheduler - Submitting ShuffleMapStage 742 (MapPartitionsRDD[3463] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:01.901 INFO  MemoryStore - Block broadcast_1363 stored as values in memory (estimated size 18.1 KiB, free 1900.2 MiB)
15:12:01.902 INFO  MemoryStore - Block broadcast_1363_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1900.2 MiB)
15:12:01.902 INFO  BlockManagerInfo - Added broadcast_1363_piece0 in memory on localhost:36687 (size: 9.5 KiB, free: 1918.1 MiB)
15:12:01.902 INFO  SparkContext - Created broadcast 1363 from broadcast at DAGScheduler.scala:1580
15:12:01.902 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 742 (MapPartitionsRDD[3463] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:01.902 INFO  TaskSchedulerImpl - Adding task set 742.0 with 1 tasks resource profile 0
15:12:01.903 INFO  TaskSetManager - Starting task 0.0 in stage 742.0 (TID 664) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:01.903 INFO  Executor - Running task 0.0 in stage 742.0 (TID 664)
15:12:01.904 INFO  ShuffleBlockFetcherIterator - Getting 1 (868.0 B) non-empty blocks including 1 (868.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.904 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.906 INFO  ShuffleBlockFetcherIterator - Getting 1 (117.0 B) non-empty blocks including 1 (117.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.906 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.908 INFO  Executor - Finished task 0.0 in stage 742.0 (TID 664). 1879 bytes result sent to driver
15:12:01.908 INFO  TaskSetManager - Finished task 0.0 in stage 742.0 (TID 664) in 6 ms on localhost (executor driver) (1/1)
15:12:01.908 INFO  TaskSchedulerImpl - Removed TaskSet 742.0, whose tasks have all completed, from pool 
15:12:01.908 INFO  DAGScheduler - ShuffleMapStage 742 (mapToPair at SparkUtils.java:161) finished in 0.008 s
15:12:01.908 INFO  DAGScheduler - looking for newly runnable stages
15:12:01.908 INFO  DAGScheduler - running: HashSet()
15:12:01.908 INFO  DAGScheduler - waiting: HashSet(ResultStage 743)
15:12:01.908 INFO  DAGScheduler - failed: HashSet()
15:12:01.909 INFO  DAGScheduler - Submitting ResultStage 743 (MapPartitionsRDD[3468] at mapToPair at BamSink.java:91), which has no missing parents
15:12:01.915 INFO  MemoryStore - Block broadcast_1364 stored as values in memory (estimated size 163.3 KiB, free 1900.0 MiB)
15:12:01.916 INFO  MemoryStore - Block broadcast_1364_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1899.9 MiB)
15:12:01.916 INFO  BlockManagerInfo - Added broadcast_1364_piece0 in memory on localhost:36687 (size: 73.4 KiB, free: 1918.1 MiB)
15:12:01.916 INFO  SparkContext - Created broadcast 1364 from broadcast at DAGScheduler.scala:1580
15:12:01.916 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 743 (MapPartitionsRDD[3468] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
15:12:01.916 INFO  TaskSchedulerImpl - Adding task set 743.0 with 1 tasks resource profile 0
15:12:01.917 INFO  TaskSetManager - Starting task 0.0 in stage 743.0 (TID 665) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:01.917 INFO  Executor - Running task 0.0 in stage 743.0 (TID 665)
15:12:01.922 INFO  ShuffleBlockFetcherIterator - Getting 1 (868.0 B) non-empty blocks including 1 (868.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:01.922 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:01.925 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:12:01.925 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:01.925 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:01.925 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:12:01.925 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:01.925 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:01.936 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271512015612541194192739786_3468_r_000000_0' to file:/tmp/local14191972300622296671/markdups14659294756510563823.bam.parts/_temporary/0/task_202505271512015612541194192739786_3468_r_000000
15:12:01.936 INFO  SparkHadoopMapRedUtil - attempt_202505271512015612541194192739786_3468_r_000000_0: Committed. Elapsed time: 0 ms.
15:12:01.937 INFO  Executor - Finished task 0.0 in stage 743.0 (TID 665). 1858 bytes result sent to driver
15:12:01.937 INFO  TaskSetManager - Finished task 0.0 in stage 743.0 (TID 665) in 20 ms on localhost (executor driver) (1/1)
15:12:01.937 INFO  TaskSchedulerImpl - Removed TaskSet 743.0, whose tasks have all completed, from pool 
15:12:01.937 INFO  DAGScheduler - ResultStage 743 (runJob at SparkHadoopWriter.scala:83) finished in 0.028 s
15:12:01.937 INFO  DAGScheduler - Job 418 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:01.937 INFO  TaskSchedulerImpl - Killing all running tasks in stage 743: Stage finished
15:12:01.938 INFO  DAGScheduler - Job 418 finished: runJob at SparkHadoopWriter.scala:83, took 0.038272 s
15:12:01.938 INFO  SparkHadoopWriter - Start to commit write Job job_202505271512015612541194192739786_3468.
15:12:01.941 INFO  SparkHadoopWriter - Write Job job_202505271512015612541194192739786_3468 committed. Elapsed time: 3 ms.
15:12:01.947 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local14191972300622296671/markdups14659294756510563823.bam
15:12:01.949 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local14191972300622296671/markdups14659294756510563823.bam done
15:12:01.949 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local14191972300622296671/markdups14659294756510563823.bam.parts/ to /tmp/local14191972300622296671/markdups14659294756510563823.bam.sbi
15:12:01.952 INFO  IndexFileMerger - Done merging .sbi files
15:12:01.952 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local14191972300622296671/markdups14659294756510563823.bam.parts/ to /tmp/local14191972300622296671/markdups14659294756510563823.bam.bai
15:12:01.955 INFO  IndexFileMerger - Done merging .bai files
15:12:01.956 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 3:12:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:03 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:03 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:03 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:04 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
15:12:26.485 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:26.485 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v93cf621-SNAPSHOT
15:12:26.485 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:12:26.485 INFO  MarkDuplicatesSpark - Executing as root@07a40c7a9995 on Linux v6.11.0-1014-azure amd64
15:12:26.485 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
15:12:26.485 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 3:12:26 PM GMT
15:12:26.485 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:26.485 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:26.485 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
15:12:26.485 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
15:12:26.485 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
15:12:26.485 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:12:26.485 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:12:26.485 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:12:26.485 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:12:26.485 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:12:26.485 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:12:26.485 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:12:26.485 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:12:26.485 INFO  MarkDuplicatesSpark - Initializing engine
15:12:26.485 INFO  MarkDuplicatesSpark - Done initializing engine
15:12:26.485 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:12:26.488 INFO  MemoryStore - Block broadcast_1941 stored as values in memory (estimated size 305.5 KiB, free 1917.1 MiB)
15:12:26.494 INFO  MemoryStore - Block broadcast_1941_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1917.1 MiB)
15:12:26.494 INFO  BlockManagerInfo - Added broadcast_1941_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1919.3 MiB)
15:12:26.494 INFO  SparkContext - Created broadcast 1941 from newAPIHadoopFile at PathSplitSource.java:96
15:12:26.515 INFO  MemoryStore - Block broadcast_1942 stored as values in memory (estimated size 305.5 KiB, free 1916.8 MiB)
15:12:26.521 INFO  MemoryStore - Block broadcast_1942_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1916.7 MiB)
15:12:26.521 INFO  BlockManagerInfo - Added broadcast_1942_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1919.2 MiB)
15:12:26.521 INFO  SparkContext - Created broadcast 1942 from newAPIHadoopFile at PathSplitSource.java:96
15:12:26.554 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:12:26.554 INFO  FileInputFormat - Total input files to process : 1
15:12:26.555 INFO  DAGScheduler - Registering RDD 5360 (mapToPair at SparkUtils.java:161) as input to shuffle 297
15:12:26.555 INFO  DAGScheduler - Got job 549 (collect at SparkUtils.java:205) with 1 output partitions
15:12:26.555 INFO  DAGScheduler - Final stage: ResultStage 1205 (collect at SparkUtils.java:205)
15:12:26.555 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1204)
15:12:26.555 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1204)
15:12:26.555 INFO  DAGScheduler - Submitting ShuffleMapStage 1204 (MapPartitionsRDD[5360] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:26.572 INFO  MemoryStore - Block broadcast_1943 stored as values in memory (estimated size 492.6 KiB, free 1916.2 MiB)
15:12:26.574 INFO  MemoryStore - Block broadcast_1943_piece0 stored as bytes in memory (estimated size 208.9 KiB, free 1916.0 MiB)
15:12:26.574 INFO  BlockManagerInfo - Added broadcast_1943_piece0 in memory on localhost:36687 (size: 208.9 KiB, free: 1919.0 MiB)
15:12:26.575 INFO  SparkContext - Created broadcast 1943 from broadcast at DAGScheduler.scala:1580
15:12:26.575 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1204 (MapPartitionsRDD[5360] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:26.575 INFO  TaskSchedulerImpl - Adding task set 1204.0 with 1 tasks resource profile 0
15:12:26.575 INFO  TaskSetManager - Starting task 0.0 in stage 1204.0 (TID 1036) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9674 bytes) 
15:12:26.575 INFO  Executor - Running task 0.0 in stage 1204.0 (TID 1036)
15:12:26.603 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam:0+13412
15:12:26.608 INFO  Executor - Finished task 0.0 in stage 1204.0 (TID 1036). 1148 bytes result sent to driver
15:12:26.608 INFO  TaskSetManager - Finished task 0.0 in stage 1204.0 (TID 1036) in 33 ms on localhost (executor driver) (1/1)
15:12:26.608 INFO  TaskSchedulerImpl - Removed TaskSet 1204.0, whose tasks have all completed, from pool 
15:12:26.608 INFO  DAGScheduler - ShuffleMapStage 1204 (mapToPair at SparkUtils.java:161) finished in 0.053 s
15:12:26.608 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.608 INFO  DAGScheduler - running: HashSet()
15:12:26.608 INFO  DAGScheduler - waiting: HashSet(ResultStage 1205)
15:12:26.608 INFO  DAGScheduler - failed: HashSet()
15:12:26.609 INFO  DAGScheduler - Submitting ResultStage 1205 (MapPartitionsRDD[5363] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:12:26.609 INFO  MemoryStore - Block broadcast_1944 stored as values in memory (estimated size 7.4 KiB, free 1916.0 MiB)
15:12:26.609 INFO  MemoryStore - Block broadcast_1944_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1916.0 MiB)
15:12:26.609 INFO  BlockManagerInfo - Added broadcast_1944_piece0 in memory on localhost:36687 (size: 4.1 KiB, free: 1919.0 MiB)
15:12:26.610 INFO  SparkContext - Created broadcast 1944 from broadcast at DAGScheduler.scala:1580
15:12:26.610 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1205 (MapPartitionsRDD[5363] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:12:26.610 INFO  TaskSchedulerImpl - Adding task set 1205.0 with 1 tasks resource profile 0
15:12:26.610 INFO  TaskSetManager - Starting task 0.0 in stage 1205.0 (TID 1037) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:26.610 INFO  Executor - Running task 0.0 in stage 1205.0 (TID 1037)
15:12:26.611 INFO  ShuffleBlockFetcherIterator - Getting 1 (16.3 KiB) non-empty blocks including 1 (16.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.611 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.613 INFO  Executor - Finished task 0.0 in stage 1205.0 (TID 1037). 2329 bytes result sent to driver
15:12:26.614 INFO  TaskSetManager - Finished task 0.0 in stage 1205.0 (TID 1037) in 4 ms on localhost (executor driver) (1/1)
15:12:26.614 INFO  TaskSchedulerImpl - Removed TaskSet 1205.0, whose tasks have all completed, from pool 
15:12:26.614 INFO  DAGScheduler - ResultStage 1205 (collect at SparkUtils.java:205) finished in 0.005 s
15:12:26.614 INFO  DAGScheduler - Job 549 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:26.614 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1205: Stage finished
15:12:26.614 INFO  DAGScheduler - Job 549 finished: collect at SparkUtils.java:205, took 0.060175 s
15:12:26.620 INFO  MemoryStore - Block broadcast_1945 stored as values in memory (estimated size 7.8 KiB, free 1916.0 MiB)
15:12:26.620 INFO  MemoryStore - Block broadcast_1945_piece0 stored as bytes in memory (estimated size 540.0 B, free 1916.0 MiB)
15:12:26.620 INFO  BlockManagerInfo - Added broadcast_1945_piece0 in memory on localhost:36687 (size: 540.0 B, free: 1919.0 MiB)
15:12:26.620 INFO  SparkContext - Created broadcast 1945 from broadcast at MarkDuplicatesSparkUtils.java:126
15:12:26.621 INFO  MemoryStore - Block broadcast_1946 stored as values in memory (estimated size 2.6 KiB, free 1916.0 MiB)
15:12:26.621 INFO  MemoryStore - Block broadcast_1946_piece0 stored as bytes in memory (estimated size 209.0 B, free 1916.0 MiB)
15:12:26.621 INFO  BlockManagerInfo - Added broadcast_1946_piece0 in memory on localhost:36687 (size: 209.0 B, free: 1919.0 MiB)
15:12:26.621 INFO  SparkContext - Created broadcast 1946 from broadcast at MarkDuplicatesSparkUtils.java:127
15:12:26.635 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:12:26.635 INFO  DAGScheduler - Registering RDD 5372 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 300
15:12:26.635 INFO  DAGScheduler - Registering RDD 5376 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 299
15:12:26.635 INFO  DAGScheduler - Registering RDD 5380 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 298
15:12:26.635 INFO  DAGScheduler - Got job 550 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:12:26.635 INFO  DAGScheduler - Final stage: ResultStage 1210 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:12:26.635 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1209)
15:12:26.635 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1209)
15:12:26.636 INFO  DAGScheduler - Submitting ShuffleMapStage 1207 (MapPartitionsRDD[5372] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:12:26.636 INFO  MemoryStore - Block broadcast_1947 stored as values in memory (estimated size 57.6 KiB, free 1916.0 MiB)
15:12:26.637 INFO  MemoryStore - Block broadcast_1947_piece0 stored as bytes in memory (estimated size 19.8 KiB, free 1915.9 MiB)
15:12:26.637 INFO  BlockManagerInfo - Added broadcast_1947_piece0 in memory on localhost:36687 (size: 19.8 KiB, free: 1919.0 MiB)
15:12:26.637 INFO  SparkContext - Created broadcast 1947 from broadcast at DAGScheduler.scala:1580
15:12:26.637 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1207 (MapPartitionsRDD[5372] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:12:26.637 INFO  TaskSchedulerImpl - Adding task set 1207.0 with 1 tasks resource profile 0
15:12:26.638 INFO  TaskSetManager - Starting task 0.0 in stage 1207.0 (TID 1038) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
15:12:26.638 INFO  Executor - Running task 0.0 in stage 1207.0 (TID 1038)
15:12:26.640 INFO  ShuffleBlockFetcherIterator - Getting 1 (16.3 KiB) non-empty blocks including 1 (16.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.640 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.643 INFO  Executor - Finished task 0.0 in stage 1207.0 (TID 1038). 1922 bytes result sent to driver
15:12:26.644 INFO  TaskSetManager - Finished task 0.0 in stage 1207.0 (TID 1038) in 6 ms on localhost (executor driver) (1/1)
15:12:26.644 INFO  TaskSchedulerImpl - Removed TaskSet 1207.0, whose tasks have all completed, from pool 
15:12:26.644 INFO  DAGScheduler - ShuffleMapStage 1207 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
15:12:26.644 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.644 INFO  DAGScheduler - running: HashSet()
15:12:26.644 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1208, ShuffleMapStage 1209, ResultStage 1210)
15:12:26.644 INFO  DAGScheduler - failed: HashSet()
15:12:26.644 INFO  DAGScheduler - Submitting ShuffleMapStage 1208 (MapPartitionsRDD[5376] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:12:26.645 INFO  MemoryStore - Block broadcast_1948 stored as values in memory (estimated size 61.7 KiB, free 1915.9 MiB)
15:12:26.645 INFO  MemoryStore - Block broadcast_1948_piece0 stored as bytes in memory (estimated size 22.0 KiB, free 1915.9 MiB)
15:12:26.646 INFO  BlockManagerInfo - Added broadcast_1948_piece0 in memory on localhost:36687 (size: 22.0 KiB, free: 1919.0 MiB)
15:12:26.646 INFO  SparkContext - Created broadcast 1948 from broadcast at DAGScheduler.scala:1580
15:12:26.646 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1208 (MapPartitionsRDD[5376] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:12:26.646 INFO  TaskSchedulerImpl - Adding task set 1208.0 with 1 tasks resource profile 0
15:12:26.646 INFO  TaskSetManager - Starting task 0.0 in stage 1208.0 (TID 1039) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
15:12:26.646 INFO  Executor - Running task 0.0 in stage 1208.0 (TID 1039)
15:12:26.648 INFO  ShuffleBlockFetcherIterator - Getting 1 (2.0 KiB) non-empty blocks including 1 (2.0 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.648 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.652 INFO  Executor - Finished task 0.0 in stage 1208.0 (TID 1039). 1922 bytes result sent to driver
15:12:26.652 INFO  TaskSetManager - Finished task 0.0 in stage 1208.0 (TID 1039) in 6 ms on localhost (executor driver) (1/1)
15:12:26.653 INFO  TaskSchedulerImpl - Removed TaskSet 1208.0, whose tasks have all completed, from pool 
15:12:26.653 INFO  DAGScheduler - ShuffleMapStage 1208 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
15:12:26.653 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.653 INFO  DAGScheduler - running: HashSet()
15:12:26.653 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1209, ResultStage 1210)
15:12:26.653 INFO  DAGScheduler - failed: HashSet()
15:12:26.653 INFO  DAGScheduler - Submitting ShuffleMapStage 1209 (MapPartitionsRDD[5380] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:12:26.654 INFO  MemoryStore - Block broadcast_1949 stored as values in memory (estimated size 52.4 KiB, free 1915.8 MiB)
15:12:26.654 INFO  MemoryStore - Block broadcast_1949_piece0 stored as bytes in memory (estimated size 17.3 KiB, free 1915.8 MiB)
15:12:26.654 INFO  BlockManagerInfo - Added broadcast_1949_piece0 in memory on localhost:36687 (size: 17.3 KiB, free: 1919.0 MiB)
15:12:26.654 INFO  SparkContext - Created broadcast 1949 from broadcast at DAGScheduler.scala:1580
15:12:26.654 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1209 (MapPartitionsRDD[5380] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:12:26.655 INFO  TaskSchedulerImpl - Adding task set 1209.0 with 1 tasks resource profile 0
15:12:26.655 INFO  TaskSetManager - Starting task 0.0 in stage 1209.0 (TID 1040) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:26.655 INFO  Executor - Running task 0.0 in stage 1209.0 (TID 1040)
15:12:26.656 INFO  ShuffleBlockFetcherIterator - Getting 1 (16.3 KiB) non-empty blocks including 1 (16.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.656 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.659 INFO  ShuffleBlockFetcherIterator - Getting 1 (2.7 KiB) non-empty blocks including 1 (2.7 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.659 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.660 INFO  Executor - Finished task 0.0 in stage 1209.0 (TID 1040). 1922 bytes result sent to driver
15:12:26.660 INFO  TaskSetManager - Finished task 0.0 in stage 1209.0 (TID 1040) in 5 ms on localhost (executor driver) (1/1)
15:12:26.660 INFO  TaskSchedulerImpl - Removed TaskSet 1209.0, whose tasks have all completed, from pool 
15:12:26.661 INFO  DAGScheduler - ShuffleMapStage 1209 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
15:12:26.661 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.661 INFO  DAGScheduler - running: HashSet()
15:12:26.661 INFO  DAGScheduler - waiting: HashSet(ResultStage 1210)
15:12:26.661 INFO  DAGScheduler - failed: HashSet()
15:12:26.661 INFO  DAGScheduler - Submitting ResultStage 1210 (MapPartitionsRDD[5382] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:12:26.662 INFO  MemoryStore - Block broadcast_1950 stored as values in memory (estimated size 53.6 KiB, free 1915.7 MiB)
15:12:26.662 INFO  MemoryStore - Block broadcast_1950_piece0 stored as bytes in memory (estimated size 18.0 KiB, free 1915.7 MiB)
15:12:26.662 INFO  BlockManagerInfo - Added broadcast_1950_piece0 in memory on localhost:36687 (size: 18.0 KiB, free: 1918.9 MiB)
15:12:26.662 INFO  SparkContext - Created broadcast 1950 from broadcast at DAGScheduler.scala:1580
15:12:26.662 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1210 (MapPartitionsRDD[5382] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:12:26.662 INFO  TaskSchedulerImpl - Adding task set 1210.0 with 1 tasks resource profile 0
15:12:26.663 INFO  TaskSetManager - Starting task 0.0 in stage 1210.0 (TID 1041) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:26.663 INFO  Executor - Running task 0.0 in stage 1210.0 (TID 1041)
15:12:26.664 INFO  ShuffleBlockFetcherIterator - Getting 1 (251.0 B) non-empty blocks including 1 (251.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.664 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.665 INFO  Executor - Finished task 0.0 in stage 1210.0 (TID 1041). 2371 bytes result sent to driver
15:12:26.665 INFO  TaskSetManager - Finished task 0.0 in stage 1210.0 (TID 1041) in 2 ms on localhost (executor driver) (1/1)
15:12:26.665 INFO  TaskSchedulerImpl - Removed TaskSet 1210.0, whose tasks have all completed, from pool 
15:12:26.665 INFO  DAGScheduler - ResultStage 1210 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.004 s
15:12:26.666 INFO  DAGScheduler - Job 550 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:26.666 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1210: Stage finished
15:12:26.666 INFO  DAGScheduler - Job 550 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.030991 s
15:12:26.676 INFO  MemoryStore - Block broadcast_1951 stored as values in memory (estimated size 179.4 KiB, free 1915.5 MiB)
15:12:26.677 INFO  MemoryStore - Block broadcast_1951_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1915.5 MiB)
15:12:26.677 INFO  BlockManagerInfo - Added broadcast_1951_piece0 in memory on localhost:36687 (size: 7.9 KiB, free: 1918.9 MiB)
15:12:26.677 INFO  SparkContext - Created broadcast 1951 from broadcast at ReadsSparkSink.java:133
15:12:26.680 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:12:26.680 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:26.680 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:26.691 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:12:26.692 INFO  DAGScheduler - Registering RDD 5384 (mapToPair at SparkUtils.java:161) as input to shuffle 301
15:12:26.692 INFO  DAGScheduler - Got job 551 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:12:26.692 INFO  DAGScheduler - Final stage: ResultStage 1215 (runJob at SparkHadoopWriter.scala:83)
15:12:26.692 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1214)
15:12:26.692 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1214)
15:12:26.692 INFO  DAGScheduler - Submitting ShuffleMapStage 1214 (MapPartitionsRDD[5384] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:26.693 INFO  MemoryStore - Block broadcast_1952 stored as values in memory (estimated size 51.5 KiB, free 1915.5 MiB)
15:12:26.693 INFO  MemoryStore - Block broadcast_1952_piece0 stored as bytes in memory (estimated size 16.8 KiB, free 1915.5 MiB)
15:12:26.694 INFO  BlockManagerInfo - Added broadcast_1952_piece0 in memory on localhost:36687 (size: 16.8 KiB, free: 1918.9 MiB)
15:12:26.694 INFO  SparkContext - Created broadcast 1952 from broadcast at DAGScheduler.scala:1580
15:12:26.694 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1214 (MapPartitionsRDD[5384] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:26.694 INFO  TaskSchedulerImpl - Adding task set 1214.0 with 1 tasks resource profile 0
15:12:26.694 INFO  TaskSetManager - Starting task 0.0 in stage 1214.0 (TID 1042) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:26.694 INFO  Executor - Running task 0.0 in stage 1214.0 (TID 1042)
15:12:26.696 INFO  ShuffleBlockFetcherIterator - Getting 1 (16.3 KiB) non-empty blocks including 1 (16.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.696 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.698 INFO  ShuffleBlockFetcherIterator - Getting 1 (2.7 KiB) non-empty blocks including 1 (2.7 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.698 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.700 INFO  Executor - Finished task 0.0 in stage 1214.0 (TID 1042). 1922 bytes result sent to driver
15:12:26.700 INFO  TaskSetManager - Finished task 0.0 in stage 1214.0 (TID 1042) in 6 ms on localhost (executor driver) (1/1)
15:12:26.700 INFO  TaskSchedulerImpl - Removed TaskSet 1214.0, whose tasks have all completed, from pool 
15:12:26.700 INFO  DAGScheduler - ShuffleMapStage 1214 (mapToPair at SparkUtils.java:161) finished in 0.008 s
15:12:26.700 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.700 INFO  DAGScheduler - running: HashSet()
15:12:26.700 INFO  DAGScheduler - waiting: HashSet(ResultStage 1215)
15:12:26.700 INFO  DAGScheduler - failed: HashSet()
15:12:26.700 INFO  DAGScheduler - Submitting ResultStage 1215 (MapPartitionsRDD[5390] at saveAsTextFile at SamSink.java:65), which has no missing parents
15:12:26.707 INFO  MemoryStore - Block broadcast_1953 stored as values in memory (estimated size 196.3 KiB, free 1915.3 MiB)
15:12:26.708 INFO  MemoryStore - Block broadcast_1953_piece0 stored as bytes in memory (estimated size 80.5 KiB, free 1915.2 MiB)
15:12:26.708 INFO  BlockManagerInfo - Added broadcast_1953_piece0 in memory on localhost:36687 (size: 80.5 KiB, free: 1918.8 MiB)
15:12:26.708 INFO  SparkContext - Created broadcast 1953 from broadcast at DAGScheduler.scala:1580
15:12:26.708 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1215 (MapPartitionsRDD[5390] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
15:12:26.708 INFO  TaskSchedulerImpl - Adding task set 1215.0 with 1 tasks resource profile 0
15:12:26.708 INFO  TaskSetManager - Starting task 0.0 in stage 1215.0 (TID 1043) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:26.708 INFO  Executor - Running task 0.0 in stage 1215.0 (TID 1043)
15:12:26.712 INFO  ShuffleBlockFetcherIterator - Getting 1 (14.8 KiB) non-empty blocks including 1 (14.8 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.712 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.714 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:12:26.714 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:26.714 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:26.720 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271512261795811993040278469_5390_m_000000_0' to file:/tmp/MarkDups17267883425184222846/MarkDups.sam.parts/_temporary/0/task_202505271512261795811993040278469_5390_m_000000
15:12:26.720 INFO  SparkHadoopMapRedUtil - attempt_202505271512261795811993040278469_5390_m_000000_0: Committed. Elapsed time: 0 ms.
15:12:26.721 INFO  Executor - Finished task 0.0 in stage 1215.0 (TID 1043). 1858 bytes result sent to driver
15:12:26.721 INFO  TaskSetManager - Finished task 0.0 in stage 1215.0 (TID 1043) in 13 ms on localhost (executor driver) (1/1)
15:12:26.721 INFO  TaskSchedulerImpl - Removed TaskSet 1215.0, whose tasks have all completed, from pool 
15:12:26.721 INFO  DAGScheduler - ResultStage 1215 (runJob at SparkHadoopWriter.scala:83) finished in 0.020 s
15:12:26.721 INFO  DAGScheduler - Job 551 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:26.721 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1215: Stage finished
15:12:26.721 INFO  DAGScheduler - Job 551 finished: runJob at SparkHadoopWriter.scala:83, took 0.029788 s
15:12:26.721 INFO  SparkHadoopWriter - Start to commit write Job job_202505271512261795811993040278469_5390.
15:12:26.724 INFO  SparkHadoopWriter - Write Job job_202505271512261795811993040278469_5390 committed. Elapsed time: 2 ms.
15:12:26.728 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups17267883425184222846/MarkDups.sam
15:12:26.730 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups17267883425184222846/MarkDups.sam done
15:12:26.731 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 3:12:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
15:12:26.750 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:26.750 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v93cf621-SNAPSHOT
15:12:26.750 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:12:26.751 INFO  MarkDuplicatesSpark - Executing as root@07a40c7a9995 on Linux v6.11.0-1014-azure amd64
15:12:26.751 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
15:12:26.751 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 3:12:26 PM GMT
15:12:26.751 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:26.751 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:26.751 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
15:12:26.751 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
15:12:26.751 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
15:12:26.751 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:12:26.751 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:12:26.751 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:12:26.751 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:12:26.751 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:12:26.751 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:12:26.751 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:12:26.751 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:12:26.751 INFO  MarkDuplicatesSpark - Initializing engine
15:12:26.751 INFO  MarkDuplicatesSpark - Done initializing engine
15:12:26.751 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:12:26.754 INFO  MemoryStore - Block broadcast_1954 stored as values in memory (estimated size 305.5 KiB, free 1914.9 MiB)
15:12:26.762 INFO  MemoryStore - Block broadcast_1954_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1914.8 MiB)
15:12:26.762 INFO  BlockManagerInfo - Added broadcast_1954_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1918.8 MiB)
15:12:26.762 INFO  SparkContext - Created broadcast 1954 from newAPIHadoopFile at PathSplitSource.java:96
15:12:26.782 INFO  MemoryStore - Block broadcast_1955 stored as values in memory (estimated size 305.5 KiB, free 1914.5 MiB)
15:12:26.788 INFO  MemoryStore - Block broadcast_1955_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1914.5 MiB)
15:12:26.788 INFO  BlockManagerInfo - Added broadcast_1955_piece0 in memory on localhost:36687 (size: 64.0 KiB, free: 1918.7 MiB)
15:12:26.789 INFO  SparkContext - Created broadcast 1955 from newAPIHadoopFile at PathSplitSource.java:96
15:12:26.819 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:12:26.820 INFO  FileInputFormat - Total input files to process : 1
15:12:26.820 INFO  DAGScheduler - Registering RDD 5404 (mapToPair at SparkUtils.java:161) as input to shuffle 302
15:12:26.820 INFO  DAGScheduler - Got job 552 (collect at SparkUtils.java:205) with 1 output partitions
15:12:26.820 INFO  DAGScheduler - Final stage: ResultStage 1217 (collect at SparkUtils.java:205)
15:12:26.820 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1216)
15:12:26.820 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1216)
15:12:26.820 INFO  DAGScheduler - Submitting ShuffleMapStage 1216 (MapPartitionsRDD[5404] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:26.844 INFO  MemoryStore - Block broadcast_1956 stored as values in memory (estimated size 456.1 KiB, free 1914.0 MiB)
15:12:26.846 INFO  MemoryStore - Block broadcast_1956_piece0 stored as bytes in memory (estimated size 200.0 KiB, free 1913.8 MiB)
15:12:26.846 INFO  BlockManagerInfo - Added broadcast_1956_piece0 in memory on localhost:36687 (size: 200.0 KiB, free: 1918.5 MiB)
15:12:26.846 INFO  SparkContext - Created broadcast 1956 from broadcast at DAGScheduler.scala:1580
15:12:26.846 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1216 (MapPartitionsRDD[5404] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:26.846 INFO  TaskSchedulerImpl - Adding task set 1216.0 with 1 tasks resource profile 0
15:12:26.847 INFO  TaskSetManager - Starting task 0.0 in stage 1216.0 (TID 1044) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9653 bytes) 
15:12:26.847 INFO  Executor - Running task 0.0 in stage 1216.0 (TID 1044)
15:12:26.874 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam:0+678
15:12:26.878 INFO  Executor - Finished task 0.0 in stage 1216.0 (TID 1044). 1148 bytes result sent to driver
15:12:26.879 INFO  TaskSetManager - Finished task 0.0 in stage 1216.0 (TID 1044) in 32 ms on localhost (executor driver) (1/1)
15:12:26.879 INFO  TaskSchedulerImpl - Removed TaskSet 1216.0, whose tasks have all completed, from pool 
15:12:26.879 INFO  DAGScheduler - ShuffleMapStage 1216 (mapToPair at SparkUtils.java:161) finished in 0.059 s
15:12:26.879 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.879 INFO  DAGScheduler - running: HashSet()
15:12:26.879 INFO  DAGScheduler - waiting: HashSet(ResultStage 1217)
15:12:26.879 INFO  DAGScheduler - failed: HashSet()
15:12:26.879 INFO  DAGScheduler - Submitting ResultStage 1217 (MapPartitionsRDD[5407] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:12:26.879 INFO  MemoryStore - Block broadcast_1957 stored as values in memory (estimated size 7.4 KiB, free 1913.8 MiB)
15:12:26.880 INFO  MemoryStore - Block broadcast_1957_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1913.8 MiB)
15:12:26.880 INFO  BlockManagerInfo - Added broadcast_1957_piece0 in memory on localhost:36687 (size: 4.1 KiB, free: 1918.5 MiB)
15:12:26.880 INFO  SparkContext - Created broadcast 1957 from broadcast at DAGScheduler.scala:1580
15:12:26.880 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1217 (MapPartitionsRDD[5407] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:12:26.880 INFO  TaskSchedulerImpl - Adding task set 1217.0 with 1 tasks resource profile 0
15:12:26.881 INFO  TaskSetManager - Starting task 0.0 in stage 1217.0 (TID 1045) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:26.881 INFO  Executor - Running task 0.0 in stage 1217.0 (TID 1045)
15:12:26.882 INFO  ShuffleBlockFetcherIterator - Getting 1 (490.0 B) non-empty blocks including 1 (490.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.882 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.883 INFO  Executor - Finished task 0.0 in stage 1217.0 (TID 1045). 2269 bytes result sent to driver
15:12:26.883 INFO  TaskSetManager - Finished task 0.0 in stage 1217.0 (TID 1045) in 2 ms on localhost (executor driver) (1/1)
15:12:26.883 INFO  TaskSchedulerImpl - Removed TaskSet 1217.0, whose tasks have all completed, from pool 
15:12:26.883 INFO  DAGScheduler - ResultStage 1217 (collect at SparkUtils.java:205) finished in 0.004 s
15:12:26.883 INFO  DAGScheduler - Job 552 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:26.883 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1217: Stage finished
15:12:26.884 INFO  DAGScheduler - Job 552 finished: collect at SparkUtils.java:205, took 0.064181 s
15:12:26.887 INFO  MemoryStore - Block broadcast_1958 stored as values in memory (estimated size 136.0 B, free 1913.8 MiB)
15:12:26.888 INFO  MemoryStore - Block broadcast_1958_piece0 stored as bytes in memory (estimated size 24.0 B, free 1913.8 MiB)
15:12:26.888 INFO  BlockManagerInfo - Added broadcast_1958_piece0 in memory on localhost:36687 (size: 24.0 B, free: 1918.5 MiB)
15:12:26.888 INFO  SparkContext - Created broadcast 1958 from broadcast at MarkDuplicatesSparkUtils.java:126
15:12:26.888 INFO  MemoryStore - Block broadcast_1959 stored as values in memory (estimated size 136.0 B, free 1913.8 MiB)
15:12:26.889 INFO  MemoryStore - Block broadcast_1959_piece0 stored as bytes in memory (estimated size 21.0 B, free 1913.8 MiB)
15:12:26.889 INFO  BlockManagerInfo - Added broadcast_1959_piece0 in memory on localhost:36687 (size: 21.0 B, free: 1918.5 MiB)
15:12:26.889 INFO  SparkContext - Created broadcast 1959 from broadcast at MarkDuplicatesSparkUtils.java:127
15:12:26.900 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:12:26.900 INFO  DAGScheduler - Registering RDD 5416 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 305
15:12:26.900 INFO  DAGScheduler - Registering RDD 5420 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 304
15:12:26.901 INFO  DAGScheduler - Registering RDD 5424 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 303
15:12:26.901 INFO  DAGScheduler - Got job 553 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:12:26.901 INFO  DAGScheduler - Final stage: ResultStage 1222 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:12:26.901 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1221)
15:12:26.901 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1221)
15:12:26.901 INFO  DAGScheduler - Submitting ShuffleMapStage 1219 (MapPartitionsRDD[5416] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:12:26.901 INFO  MemoryStore - Block broadcast_1960 stored as values in memory (estimated size 21.1 KiB, free 1913.8 MiB)
15:12:26.902 INFO  MemoryStore - Block broadcast_1960_piece0 stored as bytes in memory (estimated size 10.9 KiB, free 1913.8 MiB)
15:12:26.902 INFO  BlockManagerInfo - Added broadcast_1960_piece0 in memory on localhost:36687 (size: 10.9 KiB, free: 1918.5 MiB)
15:12:26.902 INFO  SparkContext - Created broadcast 1960 from broadcast at DAGScheduler.scala:1580
15:12:26.902 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1219 (MapPartitionsRDD[5416] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:12:26.902 INFO  TaskSchedulerImpl - Adding task set 1219.0 with 1 tasks resource profile 0
15:12:26.903 INFO  TaskSetManager - Starting task 0.0 in stage 1219.0 (TID 1046) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
15:12:26.903 INFO  Executor - Running task 0.0 in stage 1219.0 (TID 1046)
15:12:26.904 INFO  ShuffleBlockFetcherIterator - Getting 1 (490.0 B) non-empty blocks including 1 (490.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.904 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.906 INFO  Executor - Finished task 0.0 in stage 1219.0 (TID 1046). 1879 bytes result sent to driver
15:12:26.907 INFO  TaskSetManager - Finished task 0.0 in stage 1219.0 (TID 1046) in 4 ms on localhost (executor driver) (1/1)
15:12:26.907 INFO  TaskSchedulerImpl - Removed TaskSet 1219.0, whose tasks have all completed, from pool 
15:12:26.907 INFO  DAGScheduler - ShuffleMapStage 1219 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.006 s
15:12:26.907 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.907 INFO  DAGScheduler - running: HashSet()
15:12:26.907 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1220, ShuffleMapStage 1221, ResultStage 1222)
15:12:26.907 INFO  DAGScheduler - failed: HashSet()
15:12:26.907 INFO  DAGScheduler - Submitting ShuffleMapStage 1220 (MapPartitionsRDD[5420] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:12:26.908 INFO  MemoryStore - Block broadcast_1961 stored as values in memory (estimated size 25.2 KiB, free 1913.8 MiB)
15:12:26.908 INFO  MemoryStore - Block broadcast_1961_piece0 stored as bytes in memory (estimated size 13.1 KiB, free 1913.8 MiB)
15:12:26.908 INFO  BlockManagerInfo - Added broadcast_1961_piece0 in memory on localhost:36687 (size: 13.1 KiB, free: 1918.5 MiB)
15:12:26.908 INFO  SparkContext - Created broadcast 1961 from broadcast at DAGScheduler.scala:1580
15:12:26.909 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1220 (MapPartitionsRDD[5420] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:12:26.909 INFO  TaskSchedulerImpl - Adding task set 1220.0 with 1 tasks resource profile 0
15:12:26.909 INFO  TaskSetManager - Starting task 0.0 in stage 1220.0 (TID 1047) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
15:12:26.909 INFO  Executor - Running task 0.0 in stage 1220.0 (TID 1047)
15:12:26.911 INFO  ShuffleBlockFetcherIterator - Getting 1 (106.0 B) non-empty blocks including 1 (106.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.911 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.914 INFO  Executor - Finished task 0.0 in stage 1220.0 (TID 1047). 1922 bytes result sent to driver
15:12:26.914 INFO  TaskSetManager - Finished task 0.0 in stage 1220.0 (TID 1047) in 5 ms on localhost (executor driver) (1/1)
15:12:26.914 INFO  TaskSchedulerImpl - Removed TaskSet 1220.0, whose tasks have all completed, from pool 
15:12:26.915 INFO  DAGScheduler - ShuffleMapStage 1220 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
15:12:26.915 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.915 INFO  DAGScheduler - running: HashSet()
15:12:26.915 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1221, ResultStage 1222)
15:12:26.915 INFO  DAGScheduler - failed: HashSet()
15:12:26.915 INFO  DAGScheduler - Submitting ShuffleMapStage 1221 (MapPartitionsRDD[5424] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:12:26.915 INFO  MemoryStore - Block broadcast_1962 stored as values in memory (estimated size 15.9 KiB, free 1913.7 MiB)
15:12:26.916 INFO  MemoryStore - Block broadcast_1962_piece0 stored as bytes in memory (estimated size 8.3 KiB, free 1913.7 MiB)
15:12:26.916 INFO  BlockManagerInfo - Added broadcast_1962_piece0 in memory on localhost:36687 (size: 8.3 KiB, free: 1918.5 MiB)
15:12:26.916 INFO  SparkContext - Created broadcast 1962 from broadcast at DAGScheduler.scala:1580
15:12:26.916 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1221 (MapPartitionsRDD[5424] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:12:26.916 INFO  TaskSchedulerImpl - Adding task set 1221.0 with 1 tasks resource profile 0
15:12:26.917 INFO  TaskSetManager - Starting task 0.0 in stage 1221.0 (TID 1048) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:26.917 INFO  Executor - Running task 0.0 in stage 1221.0 (TID 1048)
15:12:26.918 INFO  ShuffleBlockFetcherIterator - Getting 1 (490.0 B) non-empty blocks including 1 (490.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.918 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.919 INFO  ShuffleBlockFetcherIterator - Getting 1 (60.0 B) non-empty blocks including 1 (60.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.919 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.920 INFO  Executor - Finished task 0.0 in stage 1221.0 (TID 1048). 1879 bytes result sent to driver
15:12:26.920 INFO  TaskSetManager - Finished task 0.0 in stage 1221.0 (TID 1048) in 4 ms on localhost (executor driver) (1/1)
15:12:26.920 INFO  TaskSchedulerImpl - Removed TaskSet 1221.0, whose tasks have all completed, from pool 
15:12:26.920 INFO  DAGScheduler - ShuffleMapStage 1221 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.005 s
15:12:26.920 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.920 INFO  DAGScheduler - running: HashSet()
15:12:26.920 INFO  DAGScheduler - waiting: HashSet(ResultStage 1222)
15:12:26.920 INFO  DAGScheduler - failed: HashSet()
15:12:26.921 INFO  DAGScheduler - Submitting ResultStage 1222 (MapPartitionsRDD[5426] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:12:26.921 INFO  MemoryStore - Block broadcast_1963 stored as values in memory (estimated size 17.1 KiB, free 1913.7 MiB)
15:12:26.921 INFO  MemoryStore - Block broadcast_1963_piece0 stored as bytes in memory (estimated size 9.0 KiB, free 1913.7 MiB)
15:12:26.922 INFO  BlockManagerInfo - Added broadcast_1963_piece0 in memory on localhost:36687 (size: 9.0 KiB, free: 1918.5 MiB)
15:12:26.922 INFO  SparkContext - Created broadcast 1963 from broadcast at DAGScheduler.scala:1580
15:12:26.922 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1222 (MapPartitionsRDD[5426] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:12:26.922 INFO  TaskSchedulerImpl - Adding task set 1222.0 with 1 tasks resource profile 0
15:12:26.922 INFO  TaskSetManager - Starting task 0.0 in stage 1222.0 (TID 1049) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:26.922 INFO  Executor - Running task 0.0 in stage 1222.0 (TID 1049)
15:12:26.923 INFO  ShuffleBlockFetcherIterator - Getting 1 (129.0 B) non-empty blocks including 1 (129.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.923 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.924 INFO  Executor - Finished task 0.0 in stage 1222.0 (TID 1049). 1887 bytes result sent to driver
15:12:26.924 INFO  TaskSetManager - Finished task 0.0 in stage 1222.0 (TID 1049) in 2 ms on localhost (executor driver) (1/1)
15:12:26.924 INFO  TaskSchedulerImpl - Removed TaskSet 1222.0, whose tasks have all completed, from pool 
15:12:26.925 INFO  DAGScheduler - ResultStage 1222 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.003 s
15:12:26.925 INFO  DAGScheduler - Job 553 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:26.925 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1222: Stage finished
15:12:26.925 INFO  DAGScheduler - Job 553 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.024633 s
15:12:26.934 INFO  MemoryStore - Block broadcast_1964 stored as values in memory (estimated size 5.6 KiB, free 1913.7 MiB)
15:12:26.934 INFO  MemoryStore - Block broadcast_1964_piece0 stored as bytes in memory (estimated size 500.0 B, free 1913.7 MiB)
15:12:26.934 INFO  BlockManagerInfo - Added broadcast_1964_piece0 in memory on localhost:36687 (size: 500.0 B, free: 1918.5 MiB)
15:12:26.935 INFO  SparkContext - Created broadcast 1964 from broadcast at ReadsSparkSink.java:133
15:12:26.938 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:12:26.938 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:26.938 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:26.949 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:12:26.949 INFO  DAGScheduler - Registering RDD 5428 (mapToPair at SparkUtils.java:161) as input to shuffle 306
15:12:26.950 INFO  DAGScheduler - Got job 554 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:12:26.950 INFO  DAGScheduler - Final stage: ResultStage 1227 (runJob at SparkHadoopWriter.scala:83)
15:12:26.950 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1226)
15:12:26.950 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1226)
15:12:26.950 INFO  DAGScheduler - Submitting ShuffleMapStage 1226 (MapPartitionsRDD[5428] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:26.950 INFO  MemoryStore - Block broadcast_1965 stored as values in memory (estimated size 15.0 KiB, free 1913.7 MiB)
15:12:26.951 INFO  MemoryStore - Block broadcast_1965_piece0 stored as bytes in memory (estimated size 7.8 KiB, free 1913.7 MiB)
15:12:26.951 INFO  BlockManagerInfo - Added broadcast_1965_piece0 in memory on localhost:36687 (size: 7.8 KiB, free: 1918.5 MiB)
15:12:26.951 INFO  SparkContext - Created broadcast 1965 from broadcast at DAGScheduler.scala:1580
15:12:26.951 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1226 (MapPartitionsRDD[5428] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:26.951 INFO  TaskSchedulerImpl - Adding task set 1226.0 with 1 tasks resource profile 0
15:12:26.952 INFO  TaskSetManager - Starting task 0.0 in stage 1226.0 (TID 1050) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:26.952 INFO  Executor - Running task 0.0 in stage 1226.0 (TID 1050)
15:12:26.953 INFO  ShuffleBlockFetcherIterator - Getting 1 (490.0 B) non-empty blocks including 1 (490.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.953 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.955 INFO  ShuffleBlockFetcherIterator - Getting 1 (60.0 B) non-empty blocks including 1 (60.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.955 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.956 INFO  Executor - Finished task 0.0 in stage 1226.0 (TID 1050). 1922 bytes result sent to driver
15:12:26.957 INFO  TaskSetManager - Finished task 0.0 in stage 1226.0 (TID 1050) in 6 ms on localhost (executor driver) (1/1)
15:12:26.957 INFO  TaskSchedulerImpl - Removed TaskSet 1226.0, whose tasks have all completed, from pool 
15:12:26.957 INFO  DAGScheduler - ShuffleMapStage 1226 (mapToPair at SparkUtils.java:161) finished in 0.007 s
15:12:26.957 INFO  DAGScheduler - looking for newly runnable stages
15:12:26.957 INFO  DAGScheduler - running: HashSet()
15:12:26.957 INFO  DAGScheduler - waiting: HashSet(ResultStage 1227)
15:12:26.957 INFO  DAGScheduler - failed: HashSet()
15:12:26.957 INFO  DAGScheduler - Submitting ResultStage 1227 (MapPartitionsRDD[5434] at saveAsTextFile at SamSink.java:65), which has no missing parents
15:12:26.963 INFO  MemoryStore - Block broadcast_1966 stored as values in memory (estimated size 159.8 KiB, free 1913.5 MiB)
15:12:26.964 INFO  MemoryStore - Block broadcast_1966_piece0 stored as bytes in memory (estimated size 71.5 KiB, free 1913.5 MiB)
15:12:26.964 INFO  BlockManagerInfo - Added broadcast_1966_piece0 in memory on localhost:36687 (size: 71.5 KiB, free: 1918.4 MiB)
15:12:26.964 INFO  SparkContext - Created broadcast 1966 from broadcast at DAGScheduler.scala:1580
15:12:26.964 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1227 (MapPartitionsRDD[5434] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
15:12:26.964 INFO  TaskSchedulerImpl - Adding task set 1227.0 with 1 tasks resource profile 0
15:12:26.965 INFO  TaskSetManager - Starting task 0.0 in stage 1227.0 (TID 1051) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:26.965 INFO  Executor - Running task 0.0 in stage 1227.0 (TID 1051)
15:12:26.968 INFO  ShuffleBlockFetcherIterator - Getting 1 (490.0 B) non-empty blocks including 1 (490.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:26.968 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:26.970 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:12:26.970 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:26.970 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:26.976 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271512263950033900576031685_5434_m_000000_0' to file:/tmp/MarkDups12709701828757897145/MarkDups.sam.parts/_temporary/0/task_202505271512263950033900576031685_5434_m_000000
15:12:26.976 INFO  SparkHadoopMapRedUtil - attempt_202505271512263950033900576031685_5434_m_000000_0: Committed. Elapsed time: 0 ms.
15:12:26.977 INFO  Executor - Finished task 0.0 in stage 1227.0 (TID 1051). 1858 bytes result sent to driver
15:12:26.977 INFO  TaskSetManager - Finished task 0.0 in stage 1227.0 (TID 1051) in 12 ms on localhost (executor driver) (1/1)
15:12:26.977 INFO  TaskSchedulerImpl - Removed TaskSet 1227.0, whose tasks have all completed, from pool 
15:12:26.977 INFO  DAGScheduler - ResultStage 1227 (runJob at SparkHadoopWriter.scala:83) finished in 0.020 s
15:12:26.977 INFO  DAGScheduler - Job 554 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:26.977 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1227: Stage finished
15:12:26.977 INFO  DAGScheduler - Job 554 finished: runJob at SparkHadoopWriter.scala:83, took 0.028066 s
15:12:26.977 INFO  SparkHadoopWriter - Start to commit write Job job_202505271512263950033900576031685_5434.
15:12:26.980 INFO  SparkHadoopWriter - Write Job job_202505271512263950033900576031685_5434 committed. Elapsed time: 2 ms.
15:12:26.984 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups12709701828757897145/MarkDups.sam
15:12:26.986 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups12709701828757897145/MarkDups.sam done
15:12:26.986 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 3:12:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
15:12:27.001 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:27.001 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v93cf621-SNAPSHOT
15:12:27.001 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:12:27.001 INFO  MarkDuplicatesSpark - Executing as root@07a40c7a9995 on Linux v6.11.0-1014-azure amd64
15:12:27.001 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
15:12:27.001 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 3:12:27 PM GMT
15:12:27.001 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:27.001 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:12:27.002 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
15:12:27.002 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
15:12:27.002 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
15:12:27.002 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:12:27.002 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:12:27.002 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:12:27.002 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:12:27.002 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:12:27.002 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:12:27.002 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:12:27.002 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:12:27.002 INFO  MarkDuplicatesSpark - Initializing engine
15:12:27.002 INFO  MarkDuplicatesSpark - Done initializing engine
15:12:27.002 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:12:27.004 INFO  MemoryStore - Block broadcast_1967 stored as values in memory (estimated size 305.5 KiB, free 1913.2 MiB)
15:12:27.010 INFO  MemoryStore - Block broadcast_1967_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1913.1 MiB)
15:12:27.010 INFO  BlockManagerInfo - Added broadcast_1967_piece0 in memory on localhost:36687 (size: 64.1 KiB, free: 1918.3 MiB)
15:12:27.011 INFO  SparkContext - Created broadcast 1967 from newAPIHadoopFile at PathSplitSource.java:96
15:12:27.031 INFO  MemoryStore - Block broadcast_1968 stored as values in memory (estimated size 305.5 KiB, free 1912.8 MiB)
15:12:27.038 INFO  BlockManagerInfo - Removed broadcast_1931_piece0 on localhost:36687 in memory (size: 4.1 KiB, free: 1918.3 MiB)
15:12:27.039 INFO  BlockManagerInfo - Removed broadcast_1935_piece0 on localhost:36687 in memory (size: 13.2 KiB, free: 1918.4 MiB)
15:12:27.039 INFO  BlockManagerInfo - Removed broadcast_1964_piece0 on localhost:36687 in memory (size: 500.0 B, free: 1918.4 MiB)
15:12:27.040 INFO  BlockManagerInfo - Removed broadcast_1965_piece0 on localhost:36687 in memory (size: 7.8 KiB, free: 1918.4 MiB)
15:12:27.040 INFO  BlockManagerInfo - Removed broadcast_1939_piece0 on localhost:36687 in memory (size: 8.0 KiB, free: 1918.4 MiB)
15:12:27.041 INFO  BlockManagerInfo - Removed broadcast_1950_piece0 on localhost:36687 in memory (size: 18.0 KiB, free: 1918.4 MiB)
15:12:27.041 INFO  BlockManagerInfo - Removed broadcast_1954_piece0 on localhost:36687 in memory (size: 64.0 KiB, free: 1918.5 MiB)
15:12:27.041 INFO  BlockManagerInfo - Removed broadcast_1962_piece0 on localhost:36687 in memory (size: 8.3 KiB, free: 1918.5 MiB)
15:12:27.042 INFO  BlockManagerInfo - Removed broadcast_1936_piece0 on localhost:36687 in memory (size: 8.5 KiB, free: 1918.5 MiB)
15:12:27.042 INFO  BlockManagerInfo - Removed broadcast_1930_piece0 on localhost:36687 in memory (size: 200.3 KiB, free: 1918.7 MiB)
15:12:27.042 INFO  BlockManagerInfo - Removed broadcast_1943_piece0 on localhost:36687 in memory (size: 208.9 KiB, free: 1918.9 MiB)
15:12:27.043 INFO  BlockManagerInfo - Removed broadcast_1940_piece0 on localhost:36687 in memory (size: 71.6 KiB, free: 1918.9 MiB)
15:12:27.043 INFO  BlockManagerInfo - Removed broadcast_1932_piece0 on localhost:36687 in memory (size: 19.0 B, free: 1918.9 MiB)
15:12:27.043 INFO  BlockManagerInfo - Removed broadcast_1952_piece0 on localhost:36687 in memory (size: 16.8 KiB, free: 1919.0 MiB)
15:12:27.044 INFO  BlockManagerInfo - Removed broadcast_1938_piece0 on localhost:36687 in memory (size: 663.0 B, free: 1919.0 MiB)
15:12:27.044 INFO  BlockManagerInfo - Removed broadcast_1945_piece0 on localhost:36687 in memory (size: 540.0 B, free: 1919.0 MiB)
15:12:27.044 INFO  BlockManagerInfo - Removed broadcast_1949_piece0 on localhost:36687 in memory (size: 17.3 KiB, free: 1919.0 MiB)
15:12:27.045 INFO  BlockManagerInfo - Removed broadcast_1951_piece0 on localhost:36687 in memory (size: 7.9 KiB, free: 1919.0 MiB)
15:12:27.045 INFO  BlockManagerInfo - Removed broadcast_1934_piece0 on localhost:36687 in memory (size: 11.2 KiB, free: 1919.0 MiB)
15:12:27.045 INFO  BlockManagerInfo - Removed broadcast_1947_piece0 on localhost:36687 in memory (size: 19.8 KiB, free: 1919.0 MiB)
15:12:27.046 INFO  BlockManagerInfo - Removed broadcast_1963_piece0 on localhost:36687 in memory (size: 9.0 KiB, free: 1919.0 MiB)
15:12:27.046 INFO  BlockManagerInfo - Removed broadcast_1966_piece0 on localhost:36687 in memory (size: 71.5 KiB, free: 1919.1 MiB)
15:12:27.047 INFO  BlockManagerInfo - Removed broadcast_1941_piece0 on localhost:36687 in memory (size: 64.0 KiB, free: 1919.2 MiB)
15:12:27.047 INFO  BlockManagerInfo - Removed broadcast_1928_piece0 on localhost:36687 in memory (size: 64.0 KiB, free: 1919.2 MiB)
15:12:27.047 INFO  BlockManagerInfo - Removed broadcast_1956_piece0 on localhost:36687 in memory (size: 200.0 KiB, free: 1919.4 MiB)
15:12:27.047 INFO  BlockManagerInfo - Removed broadcast_1948_piece0 on localhost:36687 in memory (size: 22.0 KiB, free: 1919.4 MiB)
15:12:27.048 INFO  MemoryStore - Block broadcast_1968_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1916.9 MiB)
15:12:27.048 INFO  BlockManagerInfo - Added broadcast_1968_piece0 in memory on localhost:36687 (size: 64.1 KiB, free: 1919.4 MiB)
15:12:27.048 INFO  BlockManagerInfo - Removed broadcast_1958_piece0 on localhost:36687 in memory (size: 24.0 B, free: 1919.4 MiB)
15:12:27.048 INFO  SparkContext - Created broadcast 1968 from newAPIHadoopFile at PathSplitSource.java:96
15:12:27.048 INFO  BlockManagerInfo - Removed broadcast_1959_piece0 on localhost:36687 in memory (size: 21.0 B, free: 1919.4 MiB)
15:12:27.048 INFO  BlockManagerInfo - Removed broadcast_1937_piece0 on localhost:36687 in memory (size: 9.1 KiB, free: 1919.4 MiB)
15:12:27.049 INFO  BlockManagerInfo - Removed broadcast_1960_piece0 on localhost:36687 in memory (size: 10.9 KiB, free: 1919.4 MiB)
15:12:27.049 INFO  BlockManagerInfo - Removed broadcast_1953_piece0 on localhost:36687 in memory (size: 80.5 KiB, free: 1919.5 MiB)
15:12:27.049 INFO  BlockManagerInfo - Removed broadcast_1955_piece0 on localhost:36687 in memory (size: 64.0 KiB, free: 1919.5 MiB)
15:12:27.050 INFO  BlockManagerInfo - Removed broadcast_1957_piece0 on localhost:36687 in memory (size: 4.1 KiB, free: 1919.5 MiB)
15:12:27.050 INFO  BlockManagerInfo - Removed broadcast_1961_piece0 on localhost:36687 in memory (size: 13.1 KiB, free: 1919.5 MiB)
15:12:27.050 INFO  BlockManagerInfo - Removed broadcast_1946_piece0 on localhost:36687 in memory (size: 209.0 B, free: 1919.5 MiB)
15:12:27.051 INFO  BlockManagerInfo - Removed broadcast_1933_piece0 on localhost:36687 in memory (size: 31.0 B, free: 1919.5 MiB)
15:12:27.051 INFO  BlockManagerInfo - Removed broadcast_1944_piece0 on localhost:36687 in memory (size: 4.1 KiB, free: 1919.6 MiB)
15:12:27.051 INFO  BlockManagerInfo - Removed broadcast_1967_piece0 on localhost:36687 in memory (size: 64.1 KiB, free: 1919.6 MiB)
15:12:27.052 INFO  BlockManagerInfo - Removed broadcast_1929_piece0 on localhost:36687 in memory (size: 64.0 KiB, free: 1919.7 MiB)
15:12:27.052 INFO  BlockManagerInfo - Removed broadcast_1942_piece0 on localhost:36687 in memory (size: 64.0 KiB, free: 1919.7 MiB)
15:12:27.082 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:12:27.082 INFO  FileInputFormat - Total input files to process : 1
15:12:27.083 INFO  DAGScheduler - Registering RDD 5448 (mapToPair at SparkUtils.java:161) as input to shuffle 307
15:12:27.083 INFO  DAGScheduler - Got job 555 (collect at SparkUtils.java:205) with 1 output partitions
15:12:27.083 INFO  DAGScheduler - Final stage: ResultStage 1229 (collect at SparkUtils.java:205)
15:12:27.083 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1228)
15:12:27.083 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1228)
15:12:27.083 INFO  DAGScheduler - Submitting ShuffleMapStage 1228 (MapPartitionsRDD[5448] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:27.100 INFO  MemoryStore - Block broadcast_1969 stored as values in memory (estimated size 480.2 KiB, free 1918.4 MiB)
15:12:27.102 INFO  MemoryStore - Block broadcast_1969_piece0 stored as bytes in memory (estimated size 206.2 KiB, free 1918.2 MiB)
15:12:27.103 INFO  BlockManagerInfo - Added broadcast_1969_piece0 in memory on localhost:36687 (size: 206.2 KiB, free: 1919.5 MiB)
15:12:27.103 INFO  SparkContext - Created broadcast 1969 from broadcast at DAGScheduler.scala:1580
15:12:27.103 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1228 (MapPartitionsRDD[5448] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:27.103 INFO  TaskSchedulerImpl - Adding task set 1228.0 with 1 tasks resource profile 0
15:12:27.103 INFO  TaskSetManager - Starting task 0.0 in stage 1228.0 (TID 1052) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9673 bytes) 
15:12:27.104 INFO  Executor - Running task 0.0 in stage 1228.0 (TID 1052)
15:12:27.131 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam:0+5416
15:12:27.136 INFO  Executor - Finished task 0.0 in stage 1228.0 (TID 1052). 1148 bytes result sent to driver
15:12:27.136 INFO  TaskSetManager - Finished task 0.0 in stage 1228.0 (TID 1052) in 33 ms on localhost (executor driver) (1/1)
15:12:27.136 INFO  TaskSchedulerImpl - Removed TaskSet 1228.0, whose tasks have all completed, from pool 
15:12:27.137 INFO  DAGScheduler - ShuffleMapStage 1228 (mapToPair at SparkUtils.java:161) finished in 0.053 s
15:12:27.137 INFO  DAGScheduler - looking for newly runnable stages
15:12:27.137 INFO  DAGScheduler - running: HashSet()
15:12:27.137 INFO  DAGScheduler - waiting: HashSet(ResultStage 1229)
15:12:27.137 INFO  DAGScheduler - failed: HashSet()
15:12:27.137 INFO  DAGScheduler - Submitting ResultStage 1229 (MapPartitionsRDD[5451] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:12:27.137 INFO  MemoryStore - Block broadcast_1970 stored as values in memory (estimated size 7.4 KiB, free 1918.2 MiB)
15:12:27.137 INFO  MemoryStore - Block broadcast_1970_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1918.2 MiB)
15:12:27.138 INFO  BlockManagerInfo - Added broadcast_1970_piece0 in memory on localhost:36687 (size: 4.1 KiB, free: 1919.5 MiB)
15:12:27.138 INFO  SparkContext - Created broadcast 1970 from broadcast at DAGScheduler.scala:1580
15:12:27.138 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1229 (MapPartitionsRDD[5451] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:12:27.138 INFO  TaskSchedulerImpl - Adding task set 1229.0 with 1 tasks resource profile 0
15:12:27.138 INFO  TaskSetManager - Starting task 0.0 in stage 1229.0 (TID 1053) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:27.138 INFO  Executor - Running task 0.0 in stage 1229.0 (TID 1053)
15:12:27.139 INFO  ShuffleBlockFetcherIterator - Getting 1 (4.3 KiB) non-empty blocks including 1 (4.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.139 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.141 INFO  Executor - Finished task 0.0 in stage 1229.0 (TID 1053). 2039 bytes result sent to driver
15:12:27.141 INFO  TaskSetManager - Finished task 0.0 in stage 1229.0 (TID 1053) in 3 ms on localhost (executor driver) (1/1)
15:12:27.141 INFO  TaskSchedulerImpl - Removed TaskSet 1229.0, whose tasks have all completed, from pool 
15:12:27.141 INFO  DAGScheduler - ResultStage 1229 (collect at SparkUtils.java:205) finished in 0.004 s
15:12:27.141 INFO  DAGScheduler - Job 555 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:27.141 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1229: Stage finished
15:12:27.141 INFO  DAGScheduler - Job 555 finished: collect at SparkUtils.java:205, took 0.058969 s
15:12:27.145 INFO  MemoryStore - Block broadcast_1971 stored as values in memory (estimated size 392.0 B, free 1918.2 MiB)
15:12:27.145 INFO  MemoryStore - Block broadcast_1971_piece0 stored as bytes in memory (estimated size 33.0 B, free 1918.2 MiB)
15:12:27.145 INFO  BlockManagerInfo - Added broadcast_1971_piece0 in memory on localhost:36687 (size: 33.0 B, free: 1919.5 MiB)
15:12:27.145 INFO  SparkContext - Created broadcast 1971 from broadcast at MarkDuplicatesSparkUtils.java:126
15:12:27.146 INFO  MemoryStore - Block broadcast_1972 stored as values in memory (estimated size 144.0 B, free 1918.2 MiB)
15:12:27.146 INFO  MemoryStore - Block broadcast_1972_piece0 stored as bytes in memory (estimated size 28.0 B, free 1918.2 MiB)
15:12:27.146 INFO  BlockManagerInfo - Added broadcast_1972_piece0 in memory on localhost:36687 (size: 28.0 B, free: 1919.5 MiB)
15:12:27.146 INFO  SparkContext - Created broadcast 1972 from broadcast at MarkDuplicatesSparkUtils.java:127
15:12:27.159 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:12:27.159 INFO  DAGScheduler - Registering RDD 5460 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 310
15:12:27.159 INFO  DAGScheduler - Registering RDD 5464 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 309
15:12:27.159 INFO  DAGScheduler - Registering RDD 5468 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 308
15:12:27.159 INFO  DAGScheduler - Got job 556 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:12:27.159 INFO  DAGScheduler - Final stage: ResultStage 1234 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:12:27.159 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1233)
15:12:27.159 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1233)
15:12:27.159 INFO  DAGScheduler - Submitting ShuffleMapStage 1231 (MapPartitionsRDD[5460] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:12:27.160 INFO  MemoryStore - Block broadcast_1973 stored as values in memory (estimated size 45.2 KiB, free 1918.1 MiB)
15:12:27.161 INFO  MemoryStore - Block broadcast_1973_piece0 stored as bytes in memory (estimated size 17.1 KiB, free 1918.1 MiB)
15:12:27.161 INFO  BlockManagerInfo - Added broadcast_1973_piece0 in memory on localhost:36687 (size: 17.1 KiB, free: 1919.5 MiB)
15:12:27.161 INFO  SparkContext - Created broadcast 1973 from broadcast at DAGScheduler.scala:1580
15:12:27.161 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1231 (MapPartitionsRDD[5460] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:12:27.161 INFO  TaskSchedulerImpl - Adding task set 1231.0 with 1 tasks resource profile 0
15:12:27.161 INFO  TaskSetManager - Starting task 0.0 in stage 1231.0 (TID 1054) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
15:12:27.162 INFO  Executor - Running task 0.0 in stage 1231.0 (TID 1054)
15:12:27.163 INFO  ShuffleBlockFetcherIterator - Getting 1 (4.3 KiB) non-empty blocks including 1 (4.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.163 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.165 INFO  Executor - Finished task 0.0 in stage 1231.0 (TID 1054). 1922 bytes result sent to driver
15:12:27.166 INFO  TaskSetManager - Finished task 0.0 in stage 1231.0 (TID 1054) in 5 ms on localhost (executor driver) (1/1)
15:12:27.166 INFO  TaskSchedulerImpl - Removed TaskSet 1231.0, whose tasks have all completed, from pool 
15:12:27.166 INFO  DAGScheduler - ShuffleMapStage 1231 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
15:12:27.166 INFO  DAGScheduler - looking for newly runnable stages
15:12:27.166 INFO  DAGScheduler - running: HashSet()
15:12:27.166 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1232, ShuffleMapStage 1233, ResultStage 1234)
15:12:27.166 INFO  DAGScheduler - failed: HashSet()
15:12:27.166 INFO  DAGScheduler - Submitting ShuffleMapStage 1232 (MapPartitionsRDD[5464] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:12:27.167 INFO  MemoryStore - Block broadcast_1974 stored as values in memory (estimated size 49.3 KiB, free 1918.0 MiB)
15:12:27.167 INFO  MemoryStore - Block broadcast_1974_piece0 stored as bytes in memory (estimated size 19.3 KiB, free 1918.0 MiB)
15:12:27.167 INFO  BlockManagerInfo - Added broadcast_1974_piece0 in memory on localhost:36687 (size: 19.3 KiB, free: 1919.5 MiB)
15:12:27.167 INFO  SparkContext - Created broadcast 1974 from broadcast at DAGScheduler.scala:1580
15:12:27.167 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1232 (MapPartitionsRDD[5464] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:12:27.167 INFO  TaskSchedulerImpl - Adding task set 1232.0 with 1 tasks resource profile 0
15:12:27.168 INFO  TaskSetManager - Starting task 0.0 in stage 1232.0 (TID 1055) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
15:12:27.168 INFO  Executor - Running task 0.0 in stage 1232.0 (TID 1055)
15:12:27.169 INFO  ShuffleBlockFetcherIterator - Getting 1 (593.0 B) non-empty blocks including 1 (593.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.169 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.172 INFO  Executor - Finished task 0.0 in stage 1232.0 (TID 1055). 1922 bytes result sent to driver
15:12:27.172 INFO  TaskSetManager - Finished task 0.0 in stage 1232.0 (TID 1055) in 4 ms on localhost (executor driver) (1/1)
15:12:27.172 INFO  TaskSchedulerImpl - Removed TaskSet 1232.0, whose tasks have all completed, from pool 
15:12:27.172 INFO  DAGScheduler - ShuffleMapStage 1232 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.006 s
15:12:27.173 INFO  DAGScheduler - looking for newly runnable stages
15:12:27.173 INFO  DAGScheduler - running: HashSet()
15:12:27.173 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1233, ResultStage 1234)
15:12:27.173 INFO  DAGScheduler - failed: HashSet()
15:12:27.173 INFO  DAGScheduler - Submitting ShuffleMapStage 1233 (MapPartitionsRDD[5468] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:12:27.173 INFO  MemoryStore - Block broadcast_1975 stored as values in memory (estimated size 40.0 KiB, free 1918.0 MiB)
15:12:27.174 INFO  MemoryStore - Block broadcast_1975_piece0 stored as bytes in memory (estimated size 14.5 KiB, free 1918.0 MiB)
15:12:27.174 INFO  BlockManagerInfo - Added broadcast_1975_piece0 in memory on localhost:36687 (size: 14.5 KiB, free: 1919.5 MiB)
15:12:27.174 INFO  SparkContext - Created broadcast 1975 from broadcast at DAGScheduler.scala:1580
15:12:27.174 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1233 (MapPartitionsRDD[5468] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:12:27.174 INFO  TaskSchedulerImpl - Adding task set 1233.0 with 1 tasks resource profile 0
15:12:27.174 INFO  TaskSetManager - Starting task 0.0 in stage 1233.0 (TID 1056) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:27.175 INFO  Executor - Running task 0.0 in stage 1233.0 (TID 1056)
15:12:27.176 INFO  ShuffleBlockFetcherIterator - Getting 1 (4.3 KiB) non-empty blocks including 1 (4.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.176 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.177 INFO  ShuffleBlockFetcherIterator - Getting 1 (652.0 B) non-empty blocks including 1 (652.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.177 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.178 INFO  Executor - Finished task 0.0 in stage 1233.0 (TID 1056). 1879 bytes result sent to driver
15:12:27.178 INFO  TaskSetManager - Finished task 0.0 in stage 1233.0 (TID 1056) in 4 ms on localhost (executor driver) (1/1)
15:12:27.178 INFO  TaskSchedulerImpl - Removed TaskSet 1233.0, whose tasks have all completed, from pool 
15:12:27.178 INFO  DAGScheduler - ShuffleMapStage 1233 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.005 s
15:12:27.178 INFO  DAGScheduler - looking for newly runnable stages
15:12:27.178 INFO  DAGScheduler - running: HashSet()
15:12:27.178 INFO  DAGScheduler - waiting: HashSet(ResultStage 1234)
15:12:27.178 INFO  DAGScheduler - failed: HashSet()
15:12:27.178 INFO  DAGScheduler - Submitting ResultStage 1234 (MapPartitionsRDD[5470] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:12:27.179 INFO  MemoryStore - Block broadcast_1976 stored as values in memory (estimated size 41.2 KiB, free 1917.9 MiB)
15:12:27.180 INFO  MemoryStore - Block broadcast_1976_piece0 stored as bytes in memory (estimated size 15.3 KiB, free 1917.9 MiB)
15:12:27.180 INFO  BlockManagerInfo - Added broadcast_1976_piece0 in memory on localhost:36687 (size: 15.3 KiB, free: 1919.5 MiB)
15:12:27.180 INFO  SparkContext - Created broadcast 1976 from broadcast at DAGScheduler.scala:1580
15:12:27.180 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1234 (MapPartitionsRDD[5470] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:12:27.180 INFO  TaskSchedulerImpl - Adding task set 1234.0 with 1 tasks resource profile 0
15:12:27.180 INFO  TaskSetManager - Starting task 0.0 in stage 1234.0 (TID 1057) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:27.180 INFO  Executor - Running task 0.0 in stage 1234.0 (TID 1057)
15:12:27.182 INFO  ShuffleBlockFetcherIterator - Getting 1 (142.0 B) non-empty blocks including 1 (142.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.182 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.183 INFO  Executor - Finished task 0.0 in stage 1234.0 (TID 1057). 1944 bytes result sent to driver
15:12:27.183 INFO  TaskSetManager - Finished task 0.0 in stage 1234.0 (TID 1057) in 3 ms on localhost (executor driver) (1/1)
15:12:27.183 INFO  TaskSchedulerImpl - Removed TaskSet 1234.0, whose tasks have all completed, from pool 
15:12:27.183 INFO  DAGScheduler - ResultStage 1234 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.004 s
15:12:27.183 INFO  DAGScheduler - Job 556 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:27.183 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1234: Stage finished
15:12:27.183 INFO  DAGScheduler - Job 556 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.024828 s
15:12:27.196 INFO  MemoryStore - Block broadcast_1977 stored as values in memory (estimated size 93.5 KiB, free 1917.8 MiB)
15:12:27.197 INFO  MemoryStore - Block broadcast_1977_piece0 stored as bytes in memory (estimated size 5.6 KiB, free 1917.8 MiB)
15:12:27.197 INFO  BlockManagerInfo - Added broadcast_1977_piece0 in memory on localhost:36687 (size: 5.6 KiB, free: 1919.5 MiB)
15:12:27.197 INFO  SparkContext - Created broadcast 1977 from broadcast at ReadsSparkSink.java:133
15:12:27.200 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:12:27.200 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:27.200 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:27.211 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:12:27.211 INFO  DAGScheduler - Registering RDD 5472 (mapToPair at SparkUtils.java:161) as input to shuffle 311
15:12:27.212 INFO  DAGScheduler - Got job 557 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:12:27.212 INFO  DAGScheduler - Final stage: ResultStage 1239 (runJob at SparkHadoopWriter.scala:83)
15:12:27.212 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1238)
15:12:27.212 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1238)
15:12:27.212 INFO  DAGScheduler - Submitting ShuffleMapStage 1238 (MapPartitionsRDD[5472] at mapToPair at SparkUtils.java:161), which has no missing parents
15:12:27.213 INFO  MemoryStore - Block broadcast_1978 stored as values in memory (estimated size 39.1 KiB, free 1917.8 MiB)
15:12:27.213 INFO  MemoryStore - Block broadcast_1978_piece0 stored as bytes in memory (estimated size 14.1 KiB, free 1917.8 MiB)
15:12:27.213 INFO  BlockManagerInfo - Added broadcast_1978_piece0 in memory on localhost:36687 (size: 14.1 KiB, free: 1919.4 MiB)
15:12:27.213 INFO  SparkContext - Created broadcast 1978 from broadcast at DAGScheduler.scala:1580
15:12:27.213 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1238 (MapPartitionsRDD[5472] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:12:27.213 INFO  TaskSchedulerImpl - Adding task set 1238.0 with 1 tasks resource profile 0
15:12:27.214 INFO  TaskSetManager - Starting task 0.0 in stage 1238.0 (TID 1058) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
15:12:27.214 INFO  Executor - Running task 0.0 in stage 1238.0 (TID 1058)
15:12:27.215 INFO  ShuffleBlockFetcherIterator - Getting 1 (4.3 KiB) non-empty blocks including 1 (4.3 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.215 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.217 INFO  ShuffleBlockFetcherIterator - Getting 1 (652.0 B) non-empty blocks including 1 (652.0 B) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.217 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.218 INFO  Executor - Finished task 0.0 in stage 1238.0 (TID 1058). 1879 bytes result sent to driver
15:12:27.218 INFO  TaskSetManager - Finished task 0.0 in stage 1238.0 (TID 1058) in 4 ms on localhost (executor driver) (1/1)
15:12:27.218 INFO  TaskSchedulerImpl - Removed TaskSet 1238.0, whose tasks have all completed, from pool 
15:12:27.218 INFO  DAGScheduler - ShuffleMapStage 1238 (mapToPair at SparkUtils.java:161) finished in 0.006 s
15:12:27.218 INFO  DAGScheduler - looking for newly runnable stages
15:12:27.218 INFO  DAGScheduler - running: HashSet()
15:12:27.218 INFO  DAGScheduler - waiting: HashSet(ResultStage 1239)
15:12:27.218 INFO  DAGScheduler - failed: HashSet()
15:12:27.218 INFO  DAGScheduler - Submitting ResultStage 1239 (MapPartitionsRDD[5478] at saveAsTextFile at SamSink.java:65), which has no missing parents
15:12:27.224 INFO  MemoryStore - Block broadcast_1979 stored as values in memory (estimated size 183.9 KiB, free 1917.6 MiB)
15:12:27.226 INFO  MemoryStore - Block broadcast_1979_piece0 stored as bytes in memory (estimated size 77.7 KiB, free 1917.5 MiB)
15:12:27.226 INFO  BlockManagerInfo - Added broadcast_1979_piece0 in memory on localhost:36687 (size: 77.7 KiB, free: 1919.4 MiB)
15:12:27.226 INFO  SparkContext - Created broadcast 1979 from broadcast at DAGScheduler.scala:1580
15:12:27.226 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1239 (MapPartitionsRDD[5478] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
15:12:27.226 INFO  TaskSchedulerImpl - Adding task set 1239.0 with 1 tasks resource profile 0
15:12:27.226 INFO  TaskSetManager - Starting task 0.0 in stage 1239.0 (TID 1059) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
15:12:27.226 INFO  Executor - Running task 0.0 in stage 1239.0 (TID 1059)
15:12:27.230 INFO  ShuffleBlockFetcherIterator - Getting 1 (3.9 KiB) non-empty blocks including 1 (3.9 KiB) local and 0 (0.0 B) host-local and 0 (0.0 B) push-merged-local and 0 (0.0 B) remote blocks
15:12:27.230 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:12:27.231 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:12:27.231 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:12:27.231 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:12:27.237 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271512273660380509223117885_5478_m_000000_0' to file:/tmp/MarkDups4545345023918793121/MarkDups.sam.parts/_temporary/0/task_202505271512273660380509223117885_5478_m_000000
15:12:27.237 INFO  SparkHadoopMapRedUtil - attempt_202505271512273660380509223117885_5478_m_000000_0: Committed. Elapsed time: 0 ms.
15:12:27.237 INFO  Executor - Finished task 0.0 in stage 1239.0 (TID 1059). 1858 bytes result sent to driver
15:12:27.237 INFO  TaskSetManager - Finished task 0.0 in stage 1239.0 (TID 1059) in 11 ms on localhost (executor driver) (1/1)
15:12:27.237 INFO  TaskSchedulerImpl - Removed TaskSet 1239.0, whose tasks have all completed, from pool 
15:12:27.237 INFO  DAGScheduler - ResultStage 1239 (runJob at SparkHadoopWriter.scala:83) finished in 0.019 s
15:12:27.237 INFO  DAGScheduler - Job 557 is finished. Cancelling potential speculative or zombie tasks for this job
15:12:27.237 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1239: Stage finished
15:12:27.237 INFO  DAGScheduler - Job 557 finished: runJob at SparkHadoopWriter.scala:83, took 0.026213 s
15:12:27.237 INFO  SparkHadoopWriter - Start to commit write Job job_202505271512273660380509223117885_5478.
15:12:27.240 INFO  SparkHadoopWriter - Write Job job_202505271512273660380509223117885_5478 committed. Elapsed time: 2 ms.
15:12:27.244 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups4545345023918793121/MarkDups.sam
15:12:27.246 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups4545345023918793121/MarkDups.sam done
15:12:27.246 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 3:12:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
15:12:32.898 ERROR Executor - Exception in task 0.0 in stage 1459.0 (TID 1206)
org.broadinstitute.hellbender.exceptions.UserException$ReadMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 is missing the read group (RG) tag, which is required by the GATK.  Please use http://gatkforums.broadinstitute.org/discussion/59/companion-utilities-replacereadgroups to fix this problem
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:64) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
15:12:32.914 ERROR TaskSetManager - Task 0 in stage 1459.0 failed 1 times; aborting job
[May 27, 2025 at 3:12:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
15:12:33.150 ERROR Executor - Exception in task 0.0 in stage 1466.0 (TID 1209)
org.broadinstitute.hellbender.exceptions.UserException$HeaderMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 contains an (RG) tag with the group NotADuplicateGroup which is not found in the file header.
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:66) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-93cf621-SNAPSHOT-local.jar:93cf621-SNAPSHOT]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
15:12:33.152 ERROR TaskSetManager - Task 0 in stage 1466.0 failed 1 times; aborting job
[May 27, 2025 at 3:12:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:51 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:51 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:51 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:53 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:53 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:53 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312
[May 27, 2025 at 3:12:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1480589312