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

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

tests
0

failures
0

ignored
59.468s

duration
100%

successful

Tests

Test Duration Result
assertThatExpectedOutputUpdateToggleIsDisabled 0s passed
testAssertAssumeUnsortedFilesAreQueryGroupedFiles 0.559s passed
testAssertCorrectSortOrderMultipleBams 0.125s passed
testAssertCorrectSortOrderMultipleBamsOverriding 0.495s passed
testBulkFragmentsNoDuplicates 0.979s passed
testBulkFragmentsWithDuplicates 2.026s passed
testDifferentChromosomesInOppositeOrder 0.300s 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.288s 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.256s 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.252s passed
testFlowModeFlag 1.499s passed
testHashCollisionHandling 0.994s 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.314s 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.314s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[0](true, true, true) 0.319s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[1](true, false, true) 0.302s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[2](false, true, true) 0.308s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[3](true, true, false) 0.303s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[4](true, false, false) 0.316s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[5](false, true, false) 0.308s passed
testMappedFragmentAndMappedPairFirstOfPairNonPrimary 0.298s passed
testMappedFragmentAndMatePairFirstUnmapped 0.302s passed
testMappedFragmentAndMatePairSecondUnmapped 0.299s passed
testMappedPairAndMappedFragmentAndMatePairFirstUnmapped 0.292s passed
testMappedPairAndMappedFragmentAndMatePairSecondUnmapped 0.316s passed
testMappedPairAndMatePairFirstOppositeStrandSecondUnmapped 0.296s passed
testMappedPairAndMatePairFirstUnmapped 0.295s passed
testMappedPairAndMatePairSecondUnmapped 0.301s passed
testMappedPairWithFirstEndSamePositionAndOther 0.294s passed
testMappedPairWithSamePosition 0.292s passed
testMappedPairWithSamePositionSameCigar 0.299s passed
testMarkDuplicatesSparkDeletingDuplicateReads[0]([Ljava.io.File;@9ea4d32, 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.374s passed
testMarkDuplicatesSparkDeletingDuplicateReads[1]([Ljava.io.File;@5fa5258f, 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.383s passed
testMarkDuplicatesSparkDeletingDuplicateReads[2]([Ljava.io.File;@40bbbbe9, 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.396s passed
testMarkDuplicatesSparkDeletingDuplicateReads[3]([Ljava.io.File;@1eff60f2, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.328s passed
testMarkDuplicatesSparkDeletingDuplicateReads[4]([Ljava.io.File;@65acc7f, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.334s passed
testMarkDuplicatesSparkDeletingDuplicateReads[5]([Ljava.io.File;@5d2b6132, 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.168s passed
testMarkDuplicatesSparkDeletingDuplicateReads[6]([Ljava.io.File;@7bd4193d, 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.135s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[0]([Ljava.io.File;@7757d3ea, 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.367s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[1]([Ljava.io.File;@20ae3645, 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
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[2]([Ljava.io.File;@4eb2e9e8, 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.372s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[3]([Ljava.io.File;@76fa2aea, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.343s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[4]([Ljava.io.File;@7f8e2056, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.336s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[5]([Ljava.io.File;@5378bbb8, 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
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[6]([Ljava.io.File;@500869d1, 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.184s passed
testMarkDuplicatesSparkIntegrationTestLocal[0]([Ljava.io.File;@1bb9b8f0, 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.330s passed
testMarkDuplicatesSparkIntegrationTestLocal[1]([Ljava.io.File;@55e97bcf, 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.347s passed
testMarkDuplicatesSparkIntegrationTestLocal[2]([Ljava.io.File;@37f3fd7, 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.362s passed
testMarkDuplicatesSparkIntegrationTestLocal[3]([Ljava.io.File;@3e75740c, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.338s passed
testMarkDuplicatesSparkIntegrationTestLocal[4]([Ljava.io.File;@5cd6864a, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.346s passed
testMarkDuplicatesSparkIntegrationTestLocal[5]([Ljava.io.File;@11c3038e, 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.219s passed
testMarkDuplicatesSparkIntegrationTestLocal[6]([Ljava.io.File;@68092c24, 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.158s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[0]([Ljava.io.File;@6123297e, 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.339s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[1]([Ljava.io.File;@44a9a6bb, 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.347s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[2]([Ljava.io.File;@5e5d7e96, 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.367s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[3]([Ljava.io.File;@55cfbbee, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.354s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[4]([Ljava.io.File;@16460359, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.328s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[5]([Ljava.io.File;@56fe2393, 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.141s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[6]([Ljava.io.File;@28391c4, 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.188s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[0]([Ljava.io.File;@501bd846, 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.352s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[1]([Ljava.io.File;@32b85017, 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.359s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[2]([Ljava.io.File;@4c919236, 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.377s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[3]([Ljava.io.File;@130c2602, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.325s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[4]([Ljava.io.File;@bc3d623, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.325s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[5]([Ljava.io.File;@276a6d0f, 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;@3a26ce1f, 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.139s passed
testMatePairFirstUnmapped 0.297s passed
testMatePairSecondUnmapped 0.329s passed
testNoReadGroupInRead 0.229s passed
testNonExistantReadGroupInRead 0.221s passed
testNullOpticalDuplicates 0.313s passed
testOpticalDuplicateClusterOneEndSamePositionOneCluster 0.305s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicatesWithinPixelDistance 0.296s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.302s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.308s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.288s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.293s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.293s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.305s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.304s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.305s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.292s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.296s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.299s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.309s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.291s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.304s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.289s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.312s passed
testOpticalDuplicateClusterSamePositionOneOpticalDuplicatesWithinPixelDistance 0.294s passed
testOpticalDuplicateClustersAddingSecondEndFirstSameCoordinate 0.308s passed
testOpticalDuplicateFinding 0.296s passed
testOpticalDuplicateFindingPxelDistance 0.296s passed
testOpticalDuplicatesAndPCRDuplicatesOrientationDifference 0.306s passed
testOpticalDuplicatesDifferentReadGroups 0.310s passed
testOpticalDuplicatesTheSameReadGroup 0.298s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.300s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.291s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.342s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.291s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.290s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.288s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.315s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.299s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.318s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.297s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.290s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.290s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.310s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.320s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.297s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.290s passed
testPathologicalOrderingAtTheSamePosition 0.293s passed
testReadSameStartPositionOrientationOverride 0.294s passed
testReadsHaveSameStartPositionButDifferentChromosomeNonEquivalence 0.289s passed
testSecondEndIsBeforeFirstInCoordinate 0.300s passed
testSingleMappedFragment 0.285s passed
testSingleMappedFragmentAndSingleMappedPair 0.288s passed
testSingleMappedFragmentAndTwoMappedPairs 0.289s passed
testSingleMappedPair 0.307s passed
testSingleUnmappedFragment 0.292s passed
testSingleUnmappedPair 0.289s passed
testStackOverFlowPairSetSwap 0.297s passed
testSupplementaryReadUnmappedMate 0.301s passed
testThreeGroupsOnDifferentChromosomesOfThreeMappedPairs 0.306s passed
testThreeMappedPairs 0.294s passed
testThreeMappedPairsWithMatchingSecondMate 0.294s passed
testTwoGroupsOnDifferentChromosomesOfThreeMappedPairs 0.290s passed
testTwoGroupsOnDifferentChromosomesOfTwoFragments 0.307s passed
testTwoGroupsOnDifferentChromosomesOfTwoMappedPairs 0.306s passed
testTwoMappedFragments 0.297s passed
testTwoMappedPairWithSamePosition 0.290s passed
testTwoMappedPairWithSamePositionDifferentStrands 0.298s passed
testTwoMappedPairWithSamePositionDifferentStrands2 0.287s passed
testTwoMappedPairs 0.289s passed
testTwoMappedPairsAndMappedSecondaryFragment 0.310s passed
testTwoMappedPairsAndTerminalUnmappedFragment 0.344s passed
testTwoMappedPairsAndTerminalUnmappedPair 0.294s passed
testTwoMappedPairsMatesSoftClipped 0.291s passed
testTwoMappedPairsWithOppositeOrientations 0.288s passed
testTwoMappedPairsWithOppositeOrientationsNumberTwo 0.302s passed
testTwoMappedPairsWithSoftClipping 0.288s passed
testTwoMappedPairsWithSoftClippingBoth 0.290s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnly 0.285s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnlyNoMateCigar 0.287s passed
testTwoMappedPairsWithSupplementaryReads[0](true, true, true) 0.298s passed
testTwoMappedPairsWithSupplementaryReads[1](true, false, true) 0.286s passed
testTwoMappedPairsWithSupplementaryReads[2](false, true, true) 0.290s passed
testTwoMappedPairsWithSupplementaryReads[3](true, true, false) 0.285s passed
testTwoMappedPairsWithSupplementaryReads[4](true, false, false) 0.298s passed
testTwoMappedPairsWithSupplementaryReads[5](false, true, false) 0.287s passed
testTwoUnmappedFragments 0.280s passed

Standard error

[May 19, 2025 at 3:44:36 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:36 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:37 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:38 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:39 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
15:44:39.796 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:44:39.796 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
15:44:39.796 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:44:39.796 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:44:39.796 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:44:39.796 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 3:44:39 PM UTC
15:44:39.796 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:44:39.796 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:44:39.796 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:44:39.796 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:44:39.796 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:44:39.797 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:44:39.797 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:44:39.797 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:44:39.797 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:44:39.797 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:44:39.797 INFO  MarkDuplicatesSpark - Initializing engine
15:44:39.797 INFO  MarkDuplicatesSpark - Done initializing engine
15:44:39.797 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:44:39.799 INFO  MemoryStore - Block broadcast_1445 stored as values in memory (estimated size 306.3 KiB, free 1896.7 MiB)
15:44:39.806 INFO  MemoryStore - Block broadcast_1445_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1896.7 MiB)
15:44:39.806 INFO  BlockManagerInfo - Added broadcast_1445_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1918.2 MiB)
15:44:39.807 INFO  SparkContext - Created broadcast 1445 from newAPIHadoopFile at PathSplitSource.java:96
15:44:39.827 INFO  MemoryStore - Block broadcast_1446 stored as values in memory (estimated size 306.3 KiB, free 1896.4 MiB)
15:44:39.834 INFO  BlockManagerInfo - Removed broadcast_1438_piece0 on localhost:44421 in memory (size: 20.0 B, free: 1918.2 MiB)
15:44:39.835 INFO  BlockManagerInfo - Removed broadcast_1439_piece0 on localhost:44421 in memory (size: 228.2 KiB, free: 1918.4 MiB)
15:44:39.835 INFO  BlockManagerInfo - Removed broadcast_1437_piece0 on localhost:44421 in memory (size: 19.0 B, free: 1918.4 MiB)
15:44:39.835 INFO  BlockManagerInfo - Removed broadcast_1435_piece0 on localhost:44421 in memory (size: 64.4 KiB, free: 1918.5 MiB)
15:44:39.836 INFO  BlockManagerInfo - Removed broadcast_1445_piece0 on localhost:44421 in memory (size: 64.4 KiB, free: 1918.6 MiB)
15:44:39.836 INFO  BlockManagerInfo - Removed broadcast_1440_piece0 on localhost:44421 in memory (size: 228.2 KiB, free: 1918.8 MiB)
15:44:39.837 INFO  BlockManagerInfo - Removed broadcast_1444_piece0 on localhost:44421 in memory (size: 324.0 KiB, free: 1919.1 MiB)
15:44:39.838 INFO  BlockManagerInfo - Removed broadcast_1443_piece0 on localhost:44421 in memory (size: 454.6 KiB, free: 1919.6 MiB)
15:44:39.840 INFO  MemoryStore - Block broadcast_1446_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1914.0 MiB)
15:44:39.840 INFO  BlockManagerInfo - Added broadcast_1446_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1919.5 MiB)
15:44:39.841 INFO  SparkContext - Created broadcast 1446 from newAPIHadoopFile at PathSplitSource.java:96
15:44:39.874 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:44:39.874 INFO  FileInputFormat - Total input files to process : 1
15:44:39.875 INFO  DAGScheduler - Registering RDD 3701 (mapToPair at SparkUtils.java:161) as input to shuffle 100
15:44:39.875 INFO  DAGScheduler - Got job 443 (collect at SparkUtils.java:205) with 1 output partitions
15:44:39.875 INFO  DAGScheduler - Final stage: ResultStage 755 (collect at SparkUtils.java:205)
15:44:39.875 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 754)
15:44:39.875 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 754)
15:44:39.876 INFO  DAGScheduler - Submitting ShuffleMapStage 754 (MapPartitionsRDD[3701] at mapToPair at SparkUtils.java:161), which has no missing parents
15:44:39.893 INFO  MemoryStore - Block broadcast_1447 stored as values in memory (estimated size 460.4 KiB, free 1913.5 MiB)
15:44:39.895 INFO  MemoryStore - Block broadcast_1447_piece0 stored as bytes in memory (estimated size 202.5 KiB, free 1913.3 MiB)
15:44:39.896 INFO  BlockManagerInfo - Added broadcast_1447_piece0 in memory on localhost:44421 (size: 202.5 KiB, free: 1919.3 MiB)
15:44:39.896 INFO  SparkContext - Created broadcast 1447 from broadcast at DAGScheduler.scala:1580
15:44:39.896 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 754 (MapPartitionsRDD[3701] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:44:39.896 INFO  TaskSchedulerImpl - Adding task set 754.0 with 1 tasks resource profile 0
15:44:39.897 INFO  TaskSetManager - Starting task 0.0 in stage 754.0 (TID 696) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9735 bytes) 
15:44:39.898 INFO  Executor - Running task 0.0 in stage 754.0 (TID 696)
15:44:39.927 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam:0+1507
15:44:39.931 INFO  Executor - Finished task 0.0 in stage 754.0 (TID 696). 1148 bytes result sent to driver
15:44:39.931 INFO  TaskSetManager - Finished task 0.0 in stage 754.0 (TID 696) in 34 ms on localhost (executor driver) (1/1)
15:44:39.932 INFO  TaskSchedulerImpl - Removed TaskSet 754.0, whose tasks have all completed, from pool 
15:44:39.932 INFO  DAGScheduler - ShuffleMapStage 754 (mapToPair at SparkUtils.java:161) finished in 0.056 s
15:44:39.932 INFO  DAGScheduler - looking for newly runnable stages
15:44:39.932 INFO  DAGScheduler - running: HashSet()
15:44:39.932 INFO  DAGScheduler - waiting: HashSet(ResultStage 755)
15:44:39.932 INFO  DAGScheduler - failed: HashSet()
15:44:39.932 INFO  DAGScheduler - Submitting ResultStage 755 (MapPartitionsRDD[3704] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:44:39.933 INFO  MemoryStore - Block broadcast_1448 stored as values in memory (estimated size 7.4 KiB, free 1913.3 MiB)
15:44:39.933 INFO  MemoryStore - Block broadcast_1448_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1913.3 MiB)
15:44:39.934 INFO  BlockManagerInfo - Added broadcast_1448_piece0 in memory on localhost:44421 (size: 4.1 KiB, free: 1919.3 MiB)
15:44:39.934 INFO  SparkContext - Created broadcast 1448 from broadcast at DAGScheduler.scala:1580
15:44:39.934 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 755 (MapPartitionsRDD[3704] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:44:39.934 INFO  TaskSchedulerImpl - Adding task set 755.0 with 1 tasks resource profile 0
15:44:39.935 INFO  TaskSetManager - Starting task 0.0 in stage 755.0 (TID 697) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:44:39.935 INFO  Executor - Running task 0.0 in stage 755.0 (TID 697)
15:44:39.936 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:44:39.936 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:39.938 INFO  Executor - Finished task 0.0 in stage 755.0 (TID 697). 2238 bytes result sent to driver
15:44:39.938 INFO  TaskSetManager - Finished task 0.0 in stage 755.0 (TID 697) in 3 ms on localhost (executor driver) (1/1)
15:44:39.938 INFO  TaskSchedulerImpl - Removed TaskSet 755.0, whose tasks have all completed, from pool 
15:44:39.939 INFO  DAGScheduler - ResultStage 755 (collect at SparkUtils.java:205) finished in 0.005 s
15:44:39.939 INFO  DAGScheduler - Job 443 is finished. Cancelling potential speculative or zombie tasks for this job
15:44:39.939 INFO  TaskSchedulerImpl - Killing all running tasks in stage 755: Stage finished
15:44:39.939 INFO  DAGScheduler - Job 443 finished: collect at SparkUtils.java:205, took 0.065268 s
15:44:39.945 INFO  MemoryStore - Block broadcast_1449 stored as values in memory (estimated size 1632.0 B, free 1913.3 MiB)
15:44:39.945 INFO  MemoryStore - Block broadcast_1449_piece0 stored as bytes in memory (estimated size 145.0 B, free 1913.3 MiB)
15:44:39.945 INFO  BlockManagerInfo - Added broadcast_1449_piece0 in memory on localhost:44421 (size: 145.0 B, free: 1919.3 MiB)
15:44:39.945 INFO  SparkContext - Created broadcast 1449 from broadcast at MarkDuplicatesSparkUtils.java:126
15:44:39.946 INFO  MemoryStore - Block broadcast_1450 stored as values in memory (estimated size 304.0 B, free 1913.3 MiB)
15:44:39.946 INFO  MemoryStore - Block broadcast_1450_piece0 stored as bytes in memory (estimated size 37.0 B, free 1913.3 MiB)
15:44:39.946 INFO  BlockManagerInfo - Added broadcast_1450_piece0 in memory on localhost:44421 (size: 37.0 B, free: 1919.3 MiB)
15:44:39.946 INFO  SparkContext - Created broadcast 1450 from broadcast at MarkDuplicatesSparkUtils.java:127
15:44:39.962 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:44:39.962 INFO  DAGScheduler - Registering RDD 3713 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 103
15:44:39.962 INFO  DAGScheduler - Registering RDD 3717 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 102
15:44:39.962 INFO  DAGScheduler - Registering RDD 3721 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 101
15:44:39.963 INFO  DAGScheduler - Got job 444 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:44:39.963 INFO  DAGScheduler - Final stage: ResultStage 760 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:44:39.963 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 759)
15:44:39.963 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 759)
15:44:39.963 INFO  DAGScheduler - Submitting ShuffleMapStage 757 (MapPartitionsRDD[3713] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:44:39.964 INFO  MemoryStore - Block broadcast_1451 stored as values in memory (estimated size 24.2 KiB, free 1913.3 MiB)
15:44:39.964 INFO  MemoryStore - Block broadcast_1451_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1913.3 MiB)
15:44:39.965 INFO  BlockManagerInfo - Added broadcast_1451_piece0 in memory on localhost:44421 (size: 12.6 KiB, free: 1919.3 MiB)
15:44:39.965 INFO  SparkContext - Created broadcast 1451 from broadcast at DAGScheduler.scala:1580
15:44:39.965 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 757 (MapPartitionsRDD[3713] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:44:39.965 INFO  TaskSchedulerImpl - Adding task set 757.0 with 1 tasks resource profile 0
15:44:39.965 INFO  TaskSetManager - Starting task 0.0 in stage 757.0 (TID 698) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
15:44:39.966 INFO  Executor - Running task 0.0 in stage 757.0 (TID 698)
15:44:39.968 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:44:39.968 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:39.971 INFO  Executor - Finished task 0.0 in stage 757.0 (TID 698). 1922 bytes result sent to driver
15:44:39.972 INFO  TaskSetManager - Finished task 0.0 in stage 757.0 (TID 698) in 7 ms on localhost (executor driver) (1/1)
15:44:39.972 INFO  TaskSchedulerImpl - Removed TaskSet 757.0, whose tasks have all completed, from pool 
15:44:39.972 INFO  DAGScheduler - ShuffleMapStage 757 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.009 s
15:44:39.972 INFO  DAGScheduler - looking for newly runnable stages
15:44:39.972 INFO  DAGScheduler - running: HashSet()
15:44:39.972 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 758, ShuffleMapStage 759, ResultStage 760)
15:44:39.972 INFO  DAGScheduler - failed: HashSet()
15:44:39.972 INFO  DAGScheduler - Submitting ShuffleMapStage 758 (MapPartitionsRDD[3717] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:44:39.973 INFO  MemoryStore - Block broadcast_1452 stored as values in memory (estimated size 28.3 KiB, free 1913.3 MiB)
15:44:39.974 INFO  MemoryStore - Block broadcast_1452_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1913.3 MiB)
15:44:39.974 INFO  BlockManagerInfo - Added broadcast_1452_piece0 in memory on localhost:44421 (size: 14.8 KiB, free: 1919.3 MiB)
15:44:39.974 INFO  SparkContext - Created broadcast 1452 from broadcast at DAGScheduler.scala:1580
15:44:39.974 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 758 (MapPartitionsRDD[3717] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:44:39.974 INFO  TaskSchedulerImpl - Adding task set 758.0 with 1 tasks resource profile 0
15:44:39.975 INFO  TaskSetManager - Starting task 0.0 in stage 758.0 (TID 699) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
15:44:39.975 INFO  Executor - Running task 0.0 in stage 758.0 (TID 699)
15:44:39.976 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:44:39.976 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:39.980 INFO  Executor - Finished task 0.0 in stage 758.0 (TID 699). 1922 bytes result sent to driver
15:44:39.980 INFO  TaskSetManager - Finished task 0.0 in stage 758.0 (TID 699) in 6 ms on localhost (executor driver) (1/1)
15:44:39.981 INFO  TaskSchedulerImpl - Removed TaskSet 758.0, whose tasks have all completed, from pool 
15:44:39.981 INFO  DAGScheduler - ShuffleMapStage 758 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
15:44:39.981 INFO  DAGScheduler - looking for newly runnable stages
15:44:39.981 INFO  DAGScheduler - running: HashSet()
15:44:39.981 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 759, ResultStage 760)
15:44:39.981 INFO  DAGScheduler - failed: HashSet()
15:44:39.981 INFO  DAGScheduler - Submitting ShuffleMapStage 759 (MapPartitionsRDD[3721] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:44:39.982 INFO  MemoryStore - Block broadcast_1453 stored as values in memory (estimated size 19.0 KiB, free 1913.2 MiB)
15:44:39.982 INFO  MemoryStore - Block broadcast_1453_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1913.2 MiB)
15:44:39.983 INFO  BlockManagerInfo - Added broadcast_1453_piece0 in memory on localhost:44421 (size: 9.7 KiB, free: 1919.2 MiB)
15:44:39.983 INFO  SparkContext - Created broadcast 1453 from broadcast at DAGScheduler.scala:1580
15:44:39.983 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 759 (MapPartitionsRDD[3721] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:44:39.983 INFO  TaskSchedulerImpl - Adding task set 759.0 with 1 tasks resource profile 0
15:44:39.983 INFO  TaskSetManager - Starting task 0.0 in stage 759.0 (TID 700) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:44:39.984 INFO  Executor - Running task 0.0 in stage 759.0 (TID 700)
15:44:39.985 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:44:39.985 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:39.987 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:44:39.987 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:39.988 INFO  Executor - Finished task 0.0 in stage 759.0 (TID 700). 1879 bytes result sent to driver
15:44:39.989 INFO  TaskSetManager - Finished task 0.0 in stage 759.0 (TID 700) in 6 ms on localhost (executor driver) (1/1)
15:44:39.989 INFO  TaskSchedulerImpl - Removed TaskSet 759.0, whose tasks have all completed, from pool 
15:44:39.989 INFO  DAGScheduler - ShuffleMapStage 759 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
15:44:39.989 INFO  DAGScheduler - looking for newly runnable stages
15:44:39.989 INFO  DAGScheduler - running: HashSet()
15:44:39.989 INFO  DAGScheduler - waiting: HashSet(ResultStage 760)
15:44:39.989 INFO  DAGScheduler - failed: HashSet()
15:44:39.989 INFO  DAGScheduler - Submitting ResultStage 760 (MapPartitionsRDD[3723] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:44:39.990 INFO  MemoryStore - Block broadcast_1454 stored as values in memory (estimated size 20.2 KiB, free 1913.2 MiB)
15:44:39.991 INFO  MemoryStore - Block broadcast_1454_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1913.2 MiB)
15:44:39.991 INFO  BlockManagerInfo - Added broadcast_1454_piece0 in memory on localhost:44421 (size: 10.6 KiB, free: 1919.2 MiB)
15:44:39.991 INFO  SparkContext - Created broadcast 1454 from broadcast at DAGScheduler.scala:1580
15:44:39.991 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 760 (MapPartitionsRDD[3723] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:44:39.991 INFO  TaskSchedulerImpl - Adding task set 760.0 with 1 tasks resource profile 0
15:44:39.992 INFO  TaskSetManager - Starting task 0.0 in stage 760.0 (TID 701) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:44:39.992 INFO  Executor - Running task 0.0 in stage 760.0 (TID 701)
15:44:39.994 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:44:39.994 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:39.996 INFO  Executor - Finished task 0.0 in stage 760.0 (TID 701). 1944 bytes result sent to driver
15:44:39.996 INFO  TaskSetManager - Finished task 0.0 in stage 760.0 (TID 701) in 4 ms on localhost (executor driver) (1/1)
15:44:39.996 INFO  TaskSchedulerImpl - Removed TaskSet 760.0, whose tasks have all completed, from pool 
15:44:39.996 INFO  DAGScheduler - ResultStage 760 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.006 s
15:44:39.997 INFO  DAGScheduler - Job 444 is finished. Cancelling potential speculative or zombie tasks for this job
15:44:39.997 INFO  TaskSchedulerImpl - Killing all running tasks in stage 760: Stage finished
15:44:39.997 INFO  DAGScheduler - Job 444 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.035131 s
15:44:40.011 INFO  MemoryStore - Block broadcast_1455 stored as values in memory (estimated size 20.3 KiB, free 1913.2 MiB)
15:44:40.011 INFO  MemoryStore - Block broadcast_1455_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1913.2 MiB)
15:44:40.011 INFO  BlockManagerInfo - Added broadcast_1455_piece0 in memory on localhost:44421 (size: 1850.0 B, free: 1919.2 MiB)
15:44:40.012 INFO  SparkContext - Created broadcast 1455 from broadcast at ReadsSparkSink.java:133
15:44:40.012 INFO  MemoryStore - Block broadcast_1456 stored as values in memory (estimated size 20.4 KiB, free 1913.2 MiB)
15:44:40.013 INFO  MemoryStore - Block broadcast_1456_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1913.1 MiB)
15:44:40.013 INFO  BlockManagerInfo - Added broadcast_1456_piece0 in memory on localhost:44421 (size: 1850.0 B, free: 1919.2 MiB)
15:44:40.013 INFO  SparkContext - Created broadcast 1456 from broadcast at BamSink.java:76
15:44:40.015 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:44:40.015 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:44:40.015 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:44:40.032 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:44:40.033 INFO  DAGScheduler - Registering RDD 3725 (mapToPair at SparkUtils.java:161) as input to shuffle 104
15:44:40.033 INFO  DAGScheduler - Got job 445 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:44:40.033 INFO  DAGScheduler - Final stage: ResultStage 765 (runJob at SparkHadoopWriter.scala:83)
15:44:40.033 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 764)
15:44:40.033 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 764)
15:44:40.033 INFO  DAGScheduler - Submitting ShuffleMapStage 764 (MapPartitionsRDD[3725] at mapToPair at SparkUtils.java:161), which has no missing parents
15:44:40.034 INFO  MemoryStore - Block broadcast_1457 stored as values in memory (estimated size 18.1 KiB, free 1913.1 MiB)
15:44:40.035 INFO  MemoryStore - Block broadcast_1457_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1913.1 MiB)
15:44:40.035 INFO  BlockManagerInfo - Added broadcast_1457_piece0 in memory on localhost:44421 (size: 9.5 KiB, free: 1919.2 MiB)
15:44:40.035 INFO  SparkContext - Created broadcast 1457 from broadcast at DAGScheduler.scala:1580
15:44:40.035 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 764 (MapPartitionsRDD[3725] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:44:40.035 INFO  TaskSchedulerImpl - Adding task set 764.0 with 1 tasks resource profile 0
15:44:40.036 INFO  TaskSetManager - Starting task 0.0 in stage 764.0 (TID 702) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:44:40.036 INFO  Executor - Running task 0.0 in stage 764.0 (TID 702)
15:44:40.038 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:44:40.038 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.040 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:44:40.040 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.041 INFO  Executor - Finished task 0.0 in stage 764.0 (TID 702). 1922 bytes result sent to driver
15:44:40.041 INFO  TaskSetManager - Finished task 0.0 in stage 764.0 (TID 702) in 5 ms on localhost (executor driver) (1/1)
15:44:40.041 INFO  TaskSchedulerImpl - Removed TaskSet 764.0, whose tasks have all completed, from pool 
15:44:40.041 INFO  DAGScheduler - ShuffleMapStage 764 (mapToPair at SparkUtils.java:161) finished in 0.007 s
15:44:40.042 INFO  DAGScheduler - looking for newly runnable stages
15:44:40.042 INFO  DAGScheduler - running: HashSet()
15:44:40.042 INFO  DAGScheduler - waiting: HashSet(ResultStage 765)
15:44:40.042 INFO  DAGScheduler - failed: HashSet()
15:44:40.042 INFO  DAGScheduler - Submitting ResultStage 765 (MapPartitionsRDD[3730] at mapToPair at BamSink.java:91), which has no missing parents
15:44:40.048 INFO  MemoryStore - Block broadcast_1458 stored as values in memory (estimated size 163.7 KiB, free 1913.0 MiB)
15:44:40.049 INFO  MemoryStore - Block broadcast_1458_piece0 stored as bytes in memory (estimated size 73.9 KiB, free 1912.9 MiB)
15:44:40.049 INFO  BlockManagerInfo - Added broadcast_1458_piece0 in memory on localhost:44421 (size: 73.9 KiB, free: 1919.2 MiB)
15:44:40.049 INFO  SparkContext - Created broadcast 1458 from broadcast at DAGScheduler.scala:1580
15:44:40.050 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 765 (MapPartitionsRDD[3730] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
15:44:40.050 INFO  TaskSchedulerImpl - Adding task set 765.0 with 1 tasks resource profile 0
15:44:40.050 INFO  TaskSetManager - Starting task 0.0 in stage 765.0 (TID 703) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:44:40.050 INFO  Executor - Running task 0.0 in stage 765.0 (TID 703)
15:44:40.054 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:44:40.054 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.056 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:44:40.056 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:44:40.056 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:44:40.056 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:44:40.056 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:44:40.056 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:44:40.074 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191544402688918990656088727_3730_r_000000_0' to file:/tmp/local16164987022877173041/markdups13166052238274061076.bam.parts/_temporary/0/task_202505191544402688918990656088727_3730_r_000000
15:44:40.074 INFO  SparkHadoopMapRedUtil - attempt_202505191544402688918990656088727_3730_r_000000_0: Committed. Elapsed time: 0 ms.
15:44:40.075 INFO  Executor - Finished task 0.0 in stage 765.0 (TID 703). 1858 bytes result sent to driver
15:44:40.075 INFO  TaskSetManager - Finished task 0.0 in stage 765.0 (TID 703) in 25 ms on localhost (executor driver) (1/1)
15:44:40.075 INFO  TaskSchedulerImpl - Removed TaskSet 765.0, whose tasks have all completed, from pool 
15:44:40.075 INFO  DAGScheduler - ResultStage 765 (runJob at SparkHadoopWriter.scala:83) finished in 0.033 s
15:44:40.075 INFO  DAGScheduler - Job 445 is finished. Cancelling potential speculative or zombie tasks for this job
15:44:40.075 INFO  TaskSchedulerImpl - Killing all running tasks in stage 765: Stage finished
15:44:40.075 INFO  DAGScheduler - Job 445 finished: runJob at SparkHadoopWriter.scala:83, took 0.042985 s
15:44:40.075 INFO  SparkHadoopWriter - Start to commit write Job job_202505191544402688918990656088727_3730.
15:44:40.080 INFO  SparkHadoopWriter - Write Job job_202505191544402688918990656088727_3730 committed. Elapsed time: 4 ms.
15:44:40.090 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local16164987022877173041/markdups13166052238274061076.bam
15:44:40.094 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local16164987022877173041/markdups13166052238274061076.bam done
15:44:40.094 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local16164987022877173041/markdups13166052238274061076.bam.parts/ to /tmp/local16164987022877173041/markdups13166052238274061076.bam.sbi
15:44:40.099 INFO  IndexFileMerger - Done merging .sbi files
15:44:40.099 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local16164987022877173041/markdups13166052238274061076.bam.parts/ to /tmp/local16164987022877173041/markdups13166052238274061076.bam.bai
15:44:40.103 INFO  IndexFileMerger - Done merging .bai files
15:44:40.103 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 3:44:40 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
15:44:40.110 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:44:40.110 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
15:44:40.110 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:44:40.110 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:44:40.110 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:44:40.110 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 3:44:40 PM UTC
15:44:40.110 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:44:40.110 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:44:40.111 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:44:40.111 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:44:40.111 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:44:40.111 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:44:40.111 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:44:40.111 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:44:40.111 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:44:40.111 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:44:40.111 INFO  MarkDuplicatesSpark - Initializing engine
15:44:40.111 INFO  MarkDuplicatesSpark - Done initializing engine
15:44:40.111 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:44:40.113 INFO  MemoryStore - Block broadcast_1459 stored as values in memory (estimated size 306.3 KiB, free 1912.6 MiB)
15:44:40.120 INFO  MemoryStore - Block broadcast_1459_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1912.5 MiB)
15:44:40.120 INFO  BlockManagerInfo - Added broadcast_1459_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1919.1 MiB)
15:44:40.120 INFO  SparkContext - Created broadcast 1459 from newAPIHadoopFile at PathSplitSource.java:96
15:44:40.149 INFO  MemoryStore - Block broadcast_1460 stored as values in memory (estimated size 306.3 KiB, free 1912.2 MiB)
15:44:40.155 INFO  MemoryStore - Block broadcast_1460_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1912.2 MiB)
15:44:40.156 INFO  BlockManagerInfo - Added broadcast_1460_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1919.0 MiB)
15:44:40.156 INFO  SparkContext - Created broadcast 1460 from newAPIHadoopFile at PathSplitSource.java:96
15:44:40.189 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:44:40.189 INFO  FileInputFormat - Total input files to process : 1
15:44:40.190 INFO  DAGScheduler - Registering RDD 3744 (mapToPair at SparkUtils.java:161) as input to shuffle 105
15:44:40.190 INFO  DAGScheduler - Got job 446 (collect at SparkUtils.java:205) with 1 output partitions
15:44:40.190 INFO  DAGScheduler - Final stage: ResultStage 767 (collect at SparkUtils.java:205)
15:44:40.190 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 766)
15:44:40.190 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 766)
15:44:40.190 INFO  DAGScheduler - Submitting ShuffleMapStage 766 (MapPartitionsRDD[3744] at mapToPair at SparkUtils.java:161), which has no missing parents
15:44:40.207 INFO  MemoryStore - Block broadcast_1461 stored as values in memory (estimated size 460.4 KiB, free 1911.7 MiB)
15:44:40.209 INFO  MemoryStore - Block broadcast_1461_piece0 stored as bytes in memory (estimated size 202.5 KiB, free 1911.5 MiB)
15:44:40.210 INFO  BlockManagerInfo - Added broadcast_1461_piece0 in memory on localhost:44421 (size: 202.5 KiB, free: 1918.8 MiB)
15:44:40.210 INFO  SparkContext - Created broadcast 1461 from broadcast at DAGScheduler.scala:1580
15:44:40.210 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 766 (MapPartitionsRDD[3744] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:44:40.210 INFO  TaskSchedulerImpl - Adding task set 766.0 with 1 tasks resource profile 0
15:44:40.211 INFO  TaskSetManager - Starting task 0.0 in stage 766.0 (TID 704) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9736 bytes) 
15:44:40.211 INFO  Executor - Running task 0.0 in stage 766.0 (TID 704)
15:44:40.247 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam:0+1856
15:44:40.251 INFO  Executor - Finished task 0.0 in stage 766.0 (TID 704). 1148 bytes result sent to driver
15:44:40.252 INFO  TaskSetManager - Finished task 0.0 in stage 766.0 (TID 704) in 41 ms on localhost (executor driver) (1/1)
15:44:40.252 INFO  TaskSchedulerImpl - Removed TaskSet 766.0, whose tasks have all completed, from pool 
15:44:40.252 INFO  DAGScheduler - ShuffleMapStage 766 (mapToPair at SparkUtils.java:161) finished in 0.062 s
15:44:40.252 INFO  DAGScheduler - looking for newly runnable stages
15:44:40.252 INFO  DAGScheduler - running: HashSet()
15:44:40.252 INFO  DAGScheduler - waiting: HashSet(ResultStage 767)
15:44:40.252 INFO  DAGScheduler - failed: HashSet()
15:44:40.252 INFO  DAGScheduler - Submitting ResultStage 767 (MapPartitionsRDD[3747] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:44:40.253 INFO  MemoryStore - Block broadcast_1462 stored as values in memory (estimated size 7.4 KiB, free 1911.5 MiB)
15:44:40.253 INFO  MemoryStore - Block broadcast_1462_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1911.5 MiB)
15:44:40.253 INFO  BlockManagerInfo - Added broadcast_1462_piece0 in memory on localhost:44421 (size: 4.1 KiB, free: 1918.8 MiB)
15:44:40.254 INFO  SparkContext - Created broadcast 1462 from broadcast at DAGScheduler.scala:1580
15:44:40.254 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 767 (MapPartitionsRDD[3747] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:44:40.254 INFO  TaskSchedulerImpl - Adding task set 767.0 with 1 tasks resource profile 0
15:44:40.254 INFO  TaskSetManager - Starting task 0.0 in stage 767.0 (TID 705) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:44:40.255 INFO  Executor - Running task 0.0 in stage 767.0 (TID 705)
15:44:40.256 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:44:40.256 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.258 INFO  Executor - Finished task 0.0 in stage 767.0 (TID 705). 2495 bytes result sent to driver
15:44:40.259 INFO  TaskSetManager - Finished task 0.0 in stage 767.0 (TID 705) in 5 ms on localhost (executor driver) (1/1)
15:44:40.259 INFO  TaskSchedulerImpl - Removed TaskSet 767.0, whose tasks have all completed, from pool 
15:44:40.259 INFO  DAGScheduler - ResultStage 767 (collect at SparkUtils.java:205) finished in 0.007 s
15:44:40.259 INFO  DAGScheduler - Job 446 is finished. Cancelling potential speculative or zombie tasks for this job
15:44:40.259 INFO  TaskSchedulerImpl - Killing all running tasks in stage 767: Stage finished
15:44:40.259 INFO  DAGScheduler - Job 446 finished: collect at SparkUtils.java:205, took 0.070133 s
15:44:40.264 INFO  MemoryStore - Block broadcast_1463 stored as values in memory (estimated size 1632.0 B, free 1911.5 MiB)
15:44:40.265 INFO  MemoryStore - Block broadcast_1463_piece0 stored as bytes in memory (estimated size 145.0 B, free 1911.5 MiB)
15:44:40.265 INFO  BlockManagerInfo - Added broadcast_1463_piece0 in memory on localhost:44421 (size: 145.0 B, free: 1918.8 MiB)
15:44:40.265 INFO  SparkContext - Created broadcast 1463 from broadcast at MarkDuplicatesSparkUtils.java:126
15:44:40.265 INFO  MemoryStore - Block broadcast_1464 stored as values in memory (estimated size 304.0 B, free 1911.5 MiB)
15:44:40.266 INFO  MemoryStore - Block broadcast_1464_piece0 stored as bytes in memory (estimated size 37.0 B, free 1911.5 MiB)
15:44:40.266 INFO  BlockManagerInfo - Added broadcast_1464_piece0 in memory on localhost:44421 (size: 37.0 B, free: 1918.8 MiB)
15:44:40.266 INFO  SparkContext - Created broadcast 1464 from broadcast at MarkDuplicatesSparkUtils.java:127
15:44:40.279 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:44:40.279 INFO  DAGScheduler - Registering RDD 3756 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 108
15:44:40.280 INFO  DAGScheduler - Registering RDD 3760 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 107
15:44:40.280 INFO  DAGScheduler - Registering RDD 3764 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 106
15:44:40.280 INFO  DAGScheduler - Got job 447 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:44:40.280 INFO  DAGScheduler - Final stage: ResultStage 772 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:44:40.280 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 771)
15:44:40.280 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 771)
15:44:40.280 INFO  DAGScheduler - Submitting ShuffleMapStage 769 (MapPartitionsRDD[3756] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:44:40.281 INFO  MemoryStore - Block broadcast_1465 stored as values in memory (estimated size 24.2 KiB, free 1911.5 MiB)
15:44:40.282 INFO  MemoryStore - Block broadcast_1465_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1911.5 MiB)
15:44:40.282 INFO  BlockManagerInfo - Added broadcast_1465_piece0 in memory on localhost:44421 (size: 12.6 KiB, free: 1918.8 MiB)
15:44:40.282 INFO  SparkContext - Created broadcast 1465 from broadcast at DAGScheduler.scala:1580
15:44:40.282 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 769 (MapPartitionsRDD[3756] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:44:40.282 INFO  TaskSchedulerImpl - Adding task set 769.0 with 1 tasks resource profile 0
15:44:40.283 INFO  TaskSetManager - Starting task 0.0 in stage 769.0 (TID 706) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
15:44:40.283 INFO  Executor - Running task 0.0 in stage 769.0 (TID 706)
15:44:40.284 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:44:40.284 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.287 INFO  Executor - Finished task 0.0 in stage 769.0 (TID 706). 1922 bytes result sent to driver
15:44:40.288 INFO  TaskSetManager - Finished task 0.0 in stage 769.0 (TID 706) in 6 ms on localhost (executor driver) (1/1)
15:44:40.288 INFO  DAGScheduler - ShuffleMapStage 769 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
15:44:40.288 INFO  DAGScheduler - looking for newly runnable stages
15:44:40.288 INFO  DAGScheduler - running: HashSet()
15:44:40.288 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 770, ShuffleMapStage 771, ResultStage 772)
15:44:40.288 INFO  DAGScheduler - failed: HashSet()
15:44:40.288 INFO  DAGScheduler - Submitting ShuffleMapStage 770 (MapPartitionsRDD[3760] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:44:40.288 INFO  TaskSchedulerImpl - Removed TaskSet 769.0, whose tasks have all completed, from pool 
15:44:40.289 INFO  MemoryStore - Block broadcast_1466 stored as values in memory (estimated size 28.3 KiB, free 1911.4 MiB)
15:44:40.290 INFO  MemoryStore - Block broadcast_1466_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1911.4 MiB)
15:44:40.290 INFO  BlockManagerInfo - Added broadcast_1466_piece0 in memory on localhost:44421 (size: 14.8 KiB, free: 1918.8 MiB)
15:44:40.290 INFO  SparkContext - Created broadcast 1466 from broadcast at DAGScheduler.scala:1580
15:44:40.290 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 770 (MapPartitionsRDD[3760] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:44:40.290 INFO  TaskSchedulerImpl - Adding task set 770.0 with 1 tasks resource profile 0
15:44:40.291 INFO  TaskSetManager - Starting task 0.0 in stage 770.0 (TID 707) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
15:44:40.291 INFO  Executor - Running task 0.0 in stage 770.0 (TID 707)
15:44:40.292 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:44:40.292 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.296 INFO  Executor - Finished task 0.0 in stage 770.0 (TID 707). 1922 bytes result sent to driver
15:44:40.297 INFO  TaskSetManager - Finished task 0.0 in stage 770.0 (TID 707) in 7 ms on localhost (executor driver) (1/1)
15:44:40.297 INFO  TaskSchedulerImpl - Removed TaskSet 770.0, whose tasks have all completed, from pool 
15:44:40.297 INFO  DAGScheduler - ShuffleMapStage 770 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
15:44:40.297 INFO  DAGScheduler - looking for newly runnable stages
15:44:40.297 INFO  DAGScheduler - running: HashSet()
15:44:40.297 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 771, ResultStage 772)
15:44:40.297 INFO  DAGScheduler - failed: HashSet()
15:44:40.297 INFO  DAGScheduler - Submitting ShuffleMapStage 771 (MapPartitionsRDD[3764] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:44:40.298 INFO  MemoryStore - Block broadcast_1467 stored as values in memory (estimated size 19.0 KiB, free 1911.4 MiB)
15:44:40.298 INFO  MemoryStore - Block broadcast_1467_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1911.4 MiB)
15:44:40.298 INFO  BlockManagerInfo - Added broadcast_1467_piece0 in memory on localhost:44421 (size: 9.7 KiB, free: 1918.8 MiB)
15:44:40.298 INFO  SparkContext - Created broadcast 1467 from broadcast at DAGScheduler.scala:1580
15:44:40.299 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 771 (MapPartitionsRDD[3764] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:44:40.299 INFO  TaskSchedulerImpl - Adding task set 771.0 with 1 tasks resource profile 0
15:44:40.299 INFO  TaskSetManager - Starting task 0.0 in stage 771.0 (TID 708) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:44:40.299 INFO  Executor - Running task 0.0 in stage 771.0 (TID 708)
15:44:40.300 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:44:40.301 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.302 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:44:40.302 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.303 INFO  Executor - Finished task 0.0 in stage 771.0 (TID 708). 1879 bytes result sent to driver
15:44:40.303 INFO  TaskSetManager - Finished task 0.0 in stage 771.0 (TID 708) in 4 ms on localhost (executor driver) (1/1)
15:44:40.304 INFO  TaskSchedulerImpl - Removed TaskSet 771.0, whose tasks have all completed, from pool 
15:44:40.304 INFO  DAGScheduler - ShuffleMapStage 771 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.007 s
15:44:40.304 INFO  DAGScheduler - looking for newly runnable stages
15:44:40.304 INFO  DAGScheduler - running: HashSet()
15:44:40.304 INFO  DAGScheduler - waiting: HashSet(ResultStage 772)
15:44:40.304 INFO  DAGScheduler - failed: HashSet()
15:44:40.304 INFO  DAGScheduler - Submitting ResultStage 772 (MapPartitionsRDD[3766] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:44:40.305 INFO  MemoryStore - Block broadcast_1468 stored as values in memory (estimated size 20.2 KiB, free 1911.4 MiB)
15:44:40.305 INFO  MemoryStore - Block broadcast_1468_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1911.4 MiB)
15:44:40.305 INFO  BlockManagerInfo - Added broadcast_1468_piece0 in memory on localhost:44421 (size: 10.6 KiB, free: 1918.8 MiB)
15:44:40.305 INFO  SparkContext - Created broadcast 1468 from broadcast at DAGScheduler.scala:1580
15:44:40.306 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 772 (MapPartitionsRDD[3766] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:44:40.306 INFO  TaskSchedulerImpl - Adding task set 772.0 with 1 tasks resource profile 0
15:44:40.306 INFO  TaskSetManager - Starting task 0.0 in stage 772.0 (TID 709) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:44:40.306 INFO  Executor - Running task 0.0 in stage 772.0 (TID 709)
15:44:40.308 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:44:40.308 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.310 INFO  Executor - Finished task 0.0 in stage 772.0 (TID 709). 2053 bytes result sent to driver
15:44:40.310 INFO  TaskSetManager - Finished task 0.0 in stage 772.0 (TID 709) in 4 ms on localhost (executor driver) (1/1)
15:44:40.310 INFO  TaskSchedulerImpl - Removed TaskSet 772.0, whose tasks have all completed, from pool 
15:44:40.310 INFO  DAGScheduler - ResultStage 772 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.006 s
15:44:40.310 INFO  DAGScheduler - Job 447 is finished. Cancelling potential speculative or zombie tasks for this job
15:44:40.310 INFO  TaskSchedulerImpl - Killing all running tasks in stage 772: Stage finished
15:44:40.311 INFO  DAGScheduler - Job 447 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.031641 s
15:44:40.325 INFO  MemoryStore - Block broadcast_1469 stored as values in memory (estimated size 20.3 KiB, free 1911.4 MiB)
15:44:40.325 INFO  MemoryStore - Block broadcast_1469_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1911.3 MiB)
15:44:40.326 INFO  BlockManagerInfo - Added broadcast_1469_piece0 in memory on localhost:44421 (size: 1850.0 B, free: 1918.8 MiB)
15:44:40.326 INFO  SparkContext - Created broadcast 1469 from broadcast at ReadsSparkSink.java:133
15:44:40.326 INFO  MemoryStore - Block broadcast_1470 stored as values in memory (estimated size 20.4 KiB, free 1911.3 MiB)
15:44:40.327 INFO  MemoryStore - Block broadcast_1470_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1911.3 MiB)
15:44:40.327 INFO  BlockManagerInfo - Added broadcast_1470_piece0 in memory on localhost:44421 (size: 1850.0 B, free: 1918.8 MiB)
15:44:40.327 INFO  SparkContext - Created broadcast 1470 from broadcast at BamSink.java:76
15:44:40.329 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:44:40.329 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:44:40.329 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:44:40.346 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:44:40.346 INFO  DAGScheduler - Registering RDD 3768 (mapToPair at SparkUtils.java:161) as input to shuffle 109
15:44:40.346 INFO  DAGScheduler - Got job 448 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:44:40.346 INFO  DAGScheduler - Final stage: ResultStage 777 (runJob at SparkHadoopWriter.scala:83)
15:44:40.346 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 776)
15:44:40.346 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 776)
15:44:40.347 INFO  DAGScheduler - Submitting ShuffleMapStage 776 (MapPartitionsRDD[3768] at mapToPair at SparkUtils.java:161), which has no missing parents
15:44:40.347 INFO  MemoryStore - Block broadcast_1471 stored as values in memory (estimated size 18.1 KiB, free 1911.3 MiB)
15:44:40.348 INFO  MemoryStore - Block broadcast_1471_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1911.3 MiB)
15:44:40.348 INFO  BlockManagerInfo - Added broadcast_1471_piece0 in memory on localhost:44421 (size: 9.5 KiB, free: 1918.8 MiB)
15:44:40.348 INFO  SparkContext - Created broadcast 1471 from broadcast at DAGScheduler.scala:1580
15:44:40.348 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 776 (MapPartitionsRDD[3768] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:44:40.348 INFO  TaskSchedulerImpl - Adding task set 776.0 with 1 tasks resource profile 0
15:44:40.349 INFO  TaskSetManager - Starting task 0.0 in stage 776.0 (TID 710) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:44:40.349 INFO  Executor - Running task 0.0 in stage 776.0 (TID 710)
15:44:40.351 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:44:40.351 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.353 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:44:40.353 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.354 INFO  Executor - Finished task 0.0 in stage 776.0 (TID 710). 1922 bytes result sent to driver
15:44:40.354 INFO  TaskSetManager - Finished task 0.0 in stage 776.0 (TID 710) in 5 ms on localhost (executor driver) (1/1)
15:44:40.354 INFO  TaskSchedulerImpl - Removed TaskSet 776.0, whose tasks have all completed, from pool 
15:44:40.354 INFO  DAGScheduler - ShuffleMapStage 776 (mapToPair at SparkUtils.java:161) finished in 0.007 s
15:44:40.354 INFO  DAGScheduler - looking for newly runnable stages
15:44:40.354 INFO  DAGScheduler - running: HashSet()
15:44:40.354 INFO  DAGScheduler - waiting: HashSet(ResultStage 777)
15:44:40.355 INFO  DAGScheduler - failed: HashSet()
15:44:40.355 INFO  DAGScheduler - Submitting ResultStage 777 (MapPartitionsRDD[3773] at mapToPair at BamSink.java:91), which has no missing parents
15:44:40.361 INFO  MemoryStore - Block broadcast_1472 stored as values in memory (estimated size 163.7 KiB, free 1911.1 MiB)
15:44:40.362 INFO  MemoryStore - Block broadcast_1472_piece0 stored as bytes in memory (estimated size 73.9 KiB, free 1911.1 MiB)
15:44:40.362 INFO  BlockManagerInfo - Added broadcast_1472_piece0 in memory on localhost:44421 (size: 73.9 KiB, free: 1918.7 MiB)
15:44:40.362 INFO  SparkContext - Created broadcast 1472 from broadcast at DAGScheduler.scala:1580
15:44:40.363 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 777 (MapPartitionsRDD[3773] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
15:44:40.363 INFO  TaskSchedulerImpl - Adding task set 777.0 with 1 tasks resource profile 0
15:44:40.363 INFO  TaskSetManager - Starting task 0.0 in stage 777.0 (TID 711) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:44:40.363 INFO  Executor - Running task 0.0 in stage 777.0 (TID 711)
15:44:40.367 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:44:40.367 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:44:40.369 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:44:40.369 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:44:40.369 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:44:40.369 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
15:44:40.369 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:44:40.369 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:44:40.388 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191544407612548726423943337_3773_r_000000_0' to file:/tmp/local16164987022877173041/markdups358998703895563703.bam.parts/_temporary/0/task_202505191544407612548726423943337_3773_r_000000
15:44:40.388 INFO  SparkHadoopMapRedUtil - attempt_202505191544407612548726423943337_3773_r_000000_0: Committed. Elapsed time: 0 ms.
15:44:40.388 INFO  Executor - Finished task 0.0 in stage 777.0 (TID 711). 1858 bytes result sent to driver
15:44:40.389 INFO  TaskSetManager - Finished task 0.0 in stage 777.0 (TID 711) in 26 ms on localhost (executor driver) (1/1)
15:44:40.389 INFO  TaskSchedulerImpl - Removed TaskSet 777.0, whose tasks have all completed, from pool 
15:44:40.389 INFO  DAGScheduler - ResultStage 777 (runJob at SparkHadoopWriter.scala:83) finished in 0.034 s
15:44:40.389 INFO  DAGScheduler - Job 448 is finished. Cancelling potential speculative or zombie tasks for this job
15:44:40.389 INFO  TaskSchedulerImpl - Killing all running tasks in stage 777: Stage finished
15:44:40.389 INFO  DAGScheduler - Job 448 finished: runJob at SparkHadoopWriter.scala:83, took 0.043480 s
15:44:40.389 INFO  SparkHadoopWriter - Start to commit write Job job_202505191544407612548726423943337_3773.
15:44:40.394 INFO  SparkHadoopWriter - Write Job job_202505191544407612548726423943337_3773 committed. Elapsed time: 4 ms.
15:44:40.404 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local16164987022877173041/markdups358998703895563703.bam
15:44:40.407 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local16164987022877173041/markdups358998703895563703.bam done
15:44:40.407 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local16164987022877173041/markdups358998703895563703.bam.parts/ to /tmp/local16164987022877173041/markdups358998703895563703.bam.sbi
15:44:40.412 INFO  IndexFileMerger - Done merging .sbi files
15:44:40.412 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local16164987022877173041/markdups358998703895563703.bam.parts/ to /tmp/local16164987022877173041/markdups358998703895563703.bam.bai
15:44:40.416 INFO  IndexFileMerger - Done merging .bai files
15:44:40.416 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 3:44:40 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:40 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:41 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:41 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:41 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:42 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:42 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:43 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:44 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:45 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:45 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:45 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:46 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:46 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:47 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:48 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:49 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:49 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:50 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:50 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:50 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:51 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:53 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:53 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:53 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:54 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:54 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:54 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:55 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:57 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:57 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:57 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:58 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:58 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:44:58 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:00 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:01 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:01 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:02 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:04 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:04 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
15:45:04.797 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:04.797 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
15:45:04.797 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:45:04.797 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:45:04.797 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:45:04.797 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 3:45:04 PM UTC
15:45:04.797 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:04.798 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:04.798 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:45:04.798 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:45:04.798 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:45:04.798 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:45:04.798 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:45:04.798 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:45:04.798 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:45:04.798 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:45:04.798 INFO  MarkDuplicatesSpark - Initializing engine
15:45:04.798 INFO  MarkDuplicatesSpark - Done initializing engine
15:45:04.798 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:45:04.800 INFO  MemoryStore - Block broadcast_2049 stored as values in memory (estimated size 306.3 KiB, free 1911.7 MiB)
15:45:04.807 INFO  MemoryStore - Block broadcast_2049_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1911.6 MiB)
15:45:04.807 INFO  BlockManagerInfo - Added broadcast_2049_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1918.9 MiB)
15:45:04.807 INFO  SparkContext - Created broadcast 2049 from newAPIHadoopFile at PathSplitSource.java:96
15:45:04.828 INFO  MemoryStore - Block broadcast_2050 stored as values in memory (estimated size 306.3 KiB, free 1911.3 MiB)
15:45:04.834 INFO  MemoryStore - Block broadcast_2050_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1911.3 MiB)
15:45:04.834 INFO  BlockManagerInfo - Added broadcast_2050_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1918.8 MiB)
15:45:04.835 INFO  SparkContext - Created broadcast 2050 from newAPIHadoopFile at PathSplitSource.java:96
15:45:04.867 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:45:04.868 INFO  FileInputFormat - Total input files to process : 1
15:45:04.868 INFO  DAGScheduler - Registering RDD 5665 (mapToPair at SparkUtils.java:161) as input to shuffle 300
15:45:04.868 INFO  DAGScheduler - Got job 579 (collect at SparkUtils.java:205) with 1 output partitions
15:45:04.868 INFO  DAGScheduler - Final stage: ResultStage 1239 (collect at SparkUtils.java:205)
15:45:04.869 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1238)
15:45:04.869 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1238)
15:45:04.869 INFO  DAGScheduler - Submitting ShuffleMapStage 1238 (MapPartitionsRDD[5665] at mapToPair at SparkUtils.java:161), which has no missing parents
15:45:04.886 INFO  MemoryStore - Block broadcast_2051 stored as values in memory (estimated size 493.8 KiB, free 1910.8 MiB)
15:45:04.889 INFO  MemoryStore - Block broadcast_2051_piece0 stored as bytes in memory (estimated size 210.1 KiB, free 1910.6 MiB)
15:45:04.889 INFO  BlockManagerInfo - Added broadcast_2051_piece0 in memory on localhost:44421 (size: 210.1 KiB, free: 1918.6 MiB)
15:45:04.889 INFO  SparkContext - Created broadcast 2051 from broadcast at DAGScheduler.scala:1580
15:45:04.889 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1238 (MapPartitionsRDD[5665] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:45:04.889 INFO  TaskSchedulerImpl - Adding task set 1238.0 with 1 tasks resource profile 0
15:45:04.890 INFO  TaskSetManager - Starting task 0.0 in stage 1238.0 (TID 1082) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9758 bytes) 
15:45:04.890 INFO  Executor - Running task 0.0 in stage 1238.0 (TID 1082)
15:45:04.919 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam:0+13412
15:45:04.925 INFO  Executor - Finished task 0.0 in stage 1238.0 (TID 1082). 1148 bytes result sent to driver
15:45:04.925 INFO  TaskSetManager - Finished task 0.0 in stage 1238.0 (TID 1082) in 35 ms on localhost (executor driver) (1/1)
15:45:04.925 INFO  TaskSchedulerImpl - Removed TaskSet 1238.0, whose tasks have all completed, from pool 
15:45:04.925 INFO  DAGScheduler - ShuffleMapStage 1238 (mapToPair at SparkUtils.java:161) finished in 0.056 s
15:45:04.925 INFO  DAGScheduler - looking for newly runnable stages
15:45:04.926 INFO  DAGScheduler - running: HashSet()
15:45:04.926 INFO  DAGScheduler - waiting: HashSet(ResultStage 1239)
15:45:04.926 INFO  DAGScheduler - failed: HashSet()
15:45:04.926 INFO  DAGScheduler - Submitting ResultStage 1239 (MapPartitionsRDD[5668] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:45:04.926 INFO  MemoryStore - Block broadcast_2052 stored as values in memory (estimated size 7.4 KiB, free 1910.6 MiB)
15:45:04.927 INFO  MemoryStore - Block broadcast_2052_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1910.6 MiB)
15:45:04.927 INFO  BlockManagerInfo - Added broadcast_2052_piece0 in memory on localhost:44421 (size: 4.1 KiB, free: 1918.6 MiB)
15:45:04.927 INFO  SparkContext - Created broadcast 2052 from broadcast at DAGScheduler.scala:1580
15:45:04.927 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1239 (MapPartitionsRDD[5668] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:45:04.928 INFO  TaskSchedulerImpl - Adding task set 1239.0 with 1 tasks resource profile 0
15:45:04.928 INFO  TaskSetManager - Starting task 0.0 in stage 1239.0 (TID 1083) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:04.928 INFO  Executor - Running task 0.0 in stage 1239.0 (TID 1083)
15:45:04.929 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:45:04.929 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:04.933 INFO  Executor - Finished task 0.0 in stage 1239.0 (TID 1083). 2329 bytes result sent to driver
15:45:04.933 INFO  TaskSetManager - Finished task 0.0 in stage 1239.0 (TID 1083) in 5 ms on localhost (executor driver) (1/1)
15:45:04.933 INFO  TaskSchedulerImpl - Removed TaskSet 1239.0, whose tasks have all completed, from pool 
15:45:04.933 INFO  DAGScheduler - ResultStage 1239 (collect at SparkUtils.java:205) finished in 0.007 s
15:45:04.934 INFO  DAGScheduler - Job 579 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:04.934 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1239: Stage finished
15:45:04.934 INFO  DAGScheduler - Job 579 finished: collect at SparkUtils.java:205, took 0.066275 s
15:45:04.938 INFO  MemoryStore - Block broadcast_2053 stored as values in memory (estimated size 7.8 KiB, free 1910.6 MiB)
15:45:04.938 INFO  MemoryStore - Block broadcast_2053_piece0 stored as bytes in memory (estimated size 540.0 B, free 1910.6 MiB)
15:45:04.938 INFO  BlockManagerInfo - Added broadcast_2053_piece0 in memory on localhost:44421 (size: 540.0 B, free: 1918.6 MiB)
15:45:04.939 INFO  SparkContext - Created broadcast 2053 from broadcast at MarkDuplicatesSparkUtils.java:126
15:45:04.939 INFO  MemoryStore - Block broadcast_2054 stored as values in memory (estimated size 2.6 KiB, free 1910.6 MiB)
15:45:04.939 INFO  MemoryStore - Block broadcast_2054_piece0 stored as bytes in memory (estimated size 209.0 B, free 1910.6 MiB)
15:45:04.939 INFO  BlockManagerInfo - Added broadcast_2054_piece0 in memory on localhost:44421 (size: 209.0 B, free: 1918.6 MiB)
15:45:04.940 INFO  SparkContext - Created broadcast 2054 from broadcast at MarkDuplicatesSparkUtils.java:127
15:45:04.953 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:45:04.954 INFO  DAGScheduler - Registering RDD 5677 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 303
15:45:04.954 INFO  DAGScheduler - Registering RDD 5681 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 302
15:45:04.954 INFO  DAGScheduler - Registering RDD 5685 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 301
15:45:04.954 INFO  DAGScheduler - Got job 580 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:45:04.954 INFO  DAGScheduler - Final stage: ResultStage 1244 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:45:04.954 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1243)
15:45:04.954 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1243)
15:45:04.955 INFO  DAGScheduler - Submitting ShuffleMapStage 1241 (MapPartitionsRDD[5677] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:45:04.956 INFO  MemoryStore - Block broadcast_2055 stored as values in memory (estimated size 57.6 KiB, free 1910.5 MiB)
15:45:04.956 INFO  MemoryStore - Block broadcast_2055_piece0 stored as bytes in memory (estimated size 19.8 KiB, free 1910.5 MiB)
15:45:04.956 INFO  BlockManagerInfo - Added broadcast_2055_piece0 in memory on localhost:44421 (size: 19.8 KiB, free: 1918.6 MiB)
15:45:04.957 INFO  SparkContext - Created broadcast 2055 from broadcast at DAGScheduler.scala:1580
15:45:04.957 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1241 (MapPartitionsRDD[5677] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:45:04.957 INFO  TaskSchedulerImpl - Adding task set 1241.0 with 1 tasks resource profile 0
15:45:04.957 INFO  TaskSetManager - Starting task 0.0 in stage 1241.0 (TID 1084) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
15:45:04.957 INFO  Executor - Running task 0.0 in stage 1241.0 (TID 1084)
15:45:04.960 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:45:04.960 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:04.965 INFO  Executor - Finished task 0.0 in stage 1241.0 (TID 1084). 1922 bytes result sent to driver
15:45:04.966 INFO  TaskSetManager - Finished task 0.0 in stage 1241.0 (TID 1084) in 9 ms on localhost (executor driver) (1/1)
15:45:04.966 INFO  TaskSchedulerImpl - Removed TaskSet 1241.0, whose tasks have all completed, from pool 
15:45:04.966 INFO  DAGScheduler - ShuffleMapStage 1241 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.011 s
15:45:04.966 INFO  DAGScheduler - looking for newly runnable stages
15:45:04.966 INFO  DAGScheduler - running: HashSet()
15:45:04.966 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1242, ShuffleMapStage 1243, ResultStage 1244)
15:45:04.966 INFO  DAGScheduler - failed: HashSet()
15:45:04.966 INFO  DAGScheduler - Submitting ShuffleMapStage 1242 (MapPartitionsRDD[5681] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:45:04.968 INFO  MemoryStore - Block broadcast_2056 stored as values in memory (estimated size 61.7 KiB, free 1910.4 MiB)
15:45:04.968 INFO  MemoryStore - Block broadcast_2056_piece0 stored as bytes in memory (estimated size 22.0 KiB, free 1910.4 MiB)
15:45:04.968 INFO  BlockManagerInfo - Added broadcast_2056_piece0 in memory on localhost:44421 (size: 22.0 KiB, free: 1918.6 MiB)
15:45:04.969 INFO  SparkContext - Created broadcast 2056 from broadcast at DAGScheduler.scala:1580
15:45:04.969 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1242 (MapPartitionsRDD[5681] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:45:04.969 INFO  TaskSchedulerImpl - Adding task set 1242.0 with 1 tasks resource profile 0
15:45:04.969 INFO  TaskSetManager - Starting task 0.0 in stage 1242.0 (TID 1085) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
15:45:04.969 INFO  Executor - Running task 0.0 in stage 1242.0 (TID 1085)
15:45:04.972 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:45:04.972 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:04.979 INFO  Executor - Finished task 0.0 in stage 1242.0 (TID 1085). 1922 bytes result sent to driver
15:45:04.980 INFO  TaskSetManager - Finished task 0.0 in stage 1242.0 (TID 1085) in 11 ms on localhost (executor driver) (1/1)
15:45:04.980 INFO  TaskSchedulerImpl - Removed TaskSet 1242.0, whose tasks have all completed, from pool 
15:45:04.980 INFO  DAGScheduler - ShuffleMapStage 1242 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.014 s
15:45:04.980 INFO  DAGScheduler - looking for newly runnable stages
15:45:04.980 INFO  DAGScheduler - running: HashSet()
15:45:04.980 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1243, ResultStage 1244)
15:45:04.980 INFO  DAGScheduler - failed: HashSet()
15:45:04.980 INFO  DAGScheduler - Submitting ShuffleMapStage 1243 (MapPartitionsRDD[5685] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:45:04.981 INFO  MemoryStore - Block broadcast_2057 stored as values in memory (estimated size 52.4 KiB, free 1910.3 MiB)
15:45:04.982 INFO  MemoryStore - Block broadcast_2057_piece0 stored as bytes in memory (estimated size 17.3 KiB, free 1910.3 MiB)
15:45:04.982 INFO  BlockManagerInfo - Added broadcast_2057_piece0 in memory on localhost:44421 (size: 17.3 KiB, free: 1918.6 MiB)
15:45:04.982 INFO  SparkContext - Created broadcast 2057 from broadcast at DAGScheduler.scala:1580
15:45:04.982 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1243 (MapPartitionsRDD[5685] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:45:04.982 INFO  TaskSchedulerImpl - Adding task set 1243.0 with 1 tasks resource profile 0
15:45:04.982 INFO  TaskSetManager - Starting task 0.0 in stage 1243.0 (TID 1086) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:45:04.983 INFO  Executor - Running task 0.0 in stage 1243.0 (TID 1086)
15:45:04.985 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:45:04.985 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:04.988 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:45:04.989 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:04.991 INFO  Executor - Finished task 0.0 in stage 1243.0 (TID 1086). 1922 bytes result sent to driver
15:45:04.991 INFO  TaskSetManager - Finished task 0.0 in stage 1243.0 (TID 1086) in 9 ms on localhost (executor driver) (1/1)
15:45:04.991 INFO  TaskSchedulerImpl - Removed TaskSet 1243.0, whose tasks have all completed, from pool 
15:45:04.991 INFO  DAGScheduler - ShuffleMapStage 1243 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.011 s
15:45:04.991 INFO  DAGScheduler - looking for newly runnable stages
15:45:04.991 INFO  DAGScheduler - running: HashSet()
15:45:04.991 INFO  DAGScheduler - waiting: HashSet(ResultStage 1244)
15:45:04.991 INFO  DAGScheduler - failed: HashSet()
15:45:04.991 INFO  DAGScheduler - Submitting ResultStage 1244 (MapPartitionsRDD[5687] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:45:04.992 INFO  MemoryStore - Block broadcast_2058 stored as values in memory (estimated size 53.6 KiB, free 1910.3 MiB)
15:45:04.993 INFO  MemoryStore - Block broadcast_2058_piece0 stored as bytes in memory (estimated size 18.0 KiB, free 1910.3 MiB)
15:45:04.993 INFO  BlockManagerInfo - Added broadcast_2058_piece0 in memory on localhost:44421 (size: 18.0 KiB, free: 1918.6 MiB)
15:45:04.993 INFO  SparkContext - Created broadcast 2058 from broadcast at DAGScheduler.scala:1580
15:45:04.993 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1244 (MapPartitionsRDD[5687] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:45:04.993 INFO  TaskSchedulerImpl - Adding task set 1244.0 with 1 tasks resource profile 0
15:45:04.993 INFO  TaskSetManager - Starting task 0.0 in stage 1244.0 (TID 1087) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:04.994 INFO  Executor - Running task 0.0 in stage 1244.0 (TID 1087)
15:45:04.995 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:45:04.995 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:04.996 INFO  Executor - Finished task 0.0 in stage 1244.0 (TID 1087). 2371 bytes result sent to driver
15:45:04.997 INFO  TaskSetManager - Finished task 0.0 in stage 1244.0 (TID 1087) in 4 ms on localhost (executor driver) (1/1)
15:45:04.997 INFO  TaskSchedulerImpl - Removed TaskSet 1244.0, whose tasks have all completed, from pool 
15:45:04.997 INFO  DAGScheduler - ResultStage 1244 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.006 s
15:45:04.997 INFO  DAGScheduler - Job 580 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:04.997 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1244: Stage finished
15:45:04.997 INFO  DAGScheduler - Job 580 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.043358 s
15:45:05.009 INFO  MemoryStore - Block broadcast_2059 stored as values in memory (estimated size 179.4 KiB, free 1910.1 MiB)
15:45:05.009 INFO  MemoryStore - Block broadcast_2059_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1910.1 MiB)
15:45:05.009 INFO  BlockManagerInfo - Added broadcast_2059_piece0 in memory on localhost:44421 (size: 7.9 KiB, free: 1918.6 MiB)
15:45:05.010 INFO  SparkContext - Created broadcast 2059 from broadcast at ReadsSparkSink.java:133
15:45:05.013 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:45:05.013 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:45:05.013 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:45:05.029 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:45:05.029 INFO  DAGScheduler - Registering RDD 5689 (mapToPair at SparkUtils.java:161) as input to shuffle 304
15:45:05.030 INFO  DAGScheduler - Got job 581 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:45:05.030 INFO  DAGScheduler - Final stage: ResultStage 1249 (runJob at SparkHadoopWriter.scala:83)
15:45:05.030 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1248)
15:45:05.030 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1248)
15:45:05.030 INFO  DAGScheduler - Submitting ShuffleMapStage 1248 (MapPartitionsRDD[5689] at mapToPair at SparkUtils.java:161), which has no missing parents
15:45:05.031 INFO  MemoryStore - Block broadcast_2060 stored as values in memory (estimated size 51.5 KiB, free 1910.0 MiB)
15:45:05.031 INFO  MemoryStore - Block broadcast_2060_piece0 stored as bytes in memory (estimated size 16.8 KiB, free 1910.0 MiB)
15:45:05.032 INFO  BlockManagerInfo - Added broadcast_2060_piece0 in memory on localhost:44421 (size: 16.8 KiB, free: 1918.5 MiB)
15:45:05.032 INFO  SparkContext - Created broadcast 2060 from broadcast at DAGScheduler.scala:1580
15:45:05.032 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1248 (MapPartitionsRDD[5689] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:45:05.032 INFO  TaskSchedulerImpl - Adding task set 1248.0 with 1 tasks resource profile 0
15:45:05.032 INFO  TaskSetManager - Starting task 0.0 in stage 1248.0 (TID 1088) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:45:05.033 INFO  Executor - Running task 0.0 in stage 1248.0 (TID 1088)
15:45:05.034 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:45:05.034 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.037 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:45:05.037 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.038 INFO  Executor - Finished task 0.0 in stage 1248.0 (TID 1088). 1922 bytes result sent to driver
15:45:05.039 INFO  TaskSetManager - Finished task 0.0 in stage 1248.0 (TID 1088) in 7 ms on localhost (executor driver) (1/1)
15:45:05.039 INFO  TaskSchedulerImpl - Removed TaskSet 1248.0, whose tasks have all completed, from pool 
15:45:05.039 INFO  DAGScheduler - ShuffleMapStage 1248 (mapToPair at SparkUtils.java:161) finished in 0.009 s
15:45:05.039 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.039 INFO  DAGScheduler - running: HashSet()
15:45:05.039 INFO  DAGScheduler - waiting: HashSet(ResultStage 1249)
15:45:05.039 INFO  DAGScheduler - failed: HashSet()
15:45:05.039 INFO  DAGScheduler - Submitting ResultStage 1249 (MapPartitionsRDD[5695] at saveAsTextFile at SamSink.java:65), which has no missing parents
15:45:05.045 INFO  MemoryStore - Block broadcast_2061 stored as values in memory (estimated size 196.7 KiB, free 1909.8 MiB)
15:45:05.046 INFO  MemoryStore - Block broadcast_2061_piece0 stored as bytes in memory (estimated size 80.9 KiB, free 1909.7 MiB)
15:45:05.047 INFO  BlockManagerInfo - Added broadcast_2061_piece0 in memory on localhost:44421 (size: 80.9 KiB, free: 1918.5 MiB)
15:45:05.047 INFO  SparkContext - Created broadcast 2061 from broadcast at DAGScheduler.scala:1580
15:45:05.047 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1249 (MapPartitionsRDD[5695] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
15:45:05.047 INFO  TaskSchedulerImpl - Adding task set 1249.0 with 1 tasks resource profile 0
15:45:05.047 INFO  TaskSetManager - Starting task 0.0 in stage 1249.0 (TID 1089) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:05.047 INFO  Executor - Running task 0.0 in stage 1249.0 (TID 1089)
15:45:05.051 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:45:05.051 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.053 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:45:05.053 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:45:05.053 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:45:05.064 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191545051225118965539118758_5695_m_000000_0' to file:/tmp/MarkDups3995242104878254518/MarkDups.sam.parts/_temporary/0/task_202505191545051225118965539118758_5695_m_000000
15:45:05.064 INFO  SparkHadoopMapRedUtil - attempt_202505191545051225118965539118758_5695_m_000000_0: Committed. Elapsed time: 0 ms.
15:45:05.064 INFO  Executor - Finished task 0.0 in stage 1249.0 (TID 1089). 1858 bytes result sent to driver
15:45:05.065 INFO  TaskSetManager - Finished task 0.0 in stage 1249.0 (TID 1089) in 18 ms on localhost (executor driver) (1/1)
15:45:05.065 INFO  TaskSchedulerImpl - Removed TaskSet 1249.0, whose tasks have all completed, from pool 
15:45:05.065 INFO  DAGScheduler - ResultStage 1249 (runJob at SparkHadoopWriter.scala:83) finished in 0.026 s
15:45:05.065 INFO  DAGScheduler - Job 581 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:05.065 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1249: Stage finished
15:45:05.065 INFO  DAGScheduler - Job 581 finished: runJob at SparkHadoopWriter.scala:83, took 0.035879 s
15:45:05.065 INFO  SparkHadoopWriter - Start to commit write Job job_202505191545051225118965539118758_5695.
15:45:05.069 INFO  SparkHadoopWriter - Write Job job_202505191545051225118965539118758_5695 committed. Elapsed time: 3 ms.
15:45:05.076 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups3995242104878254518/MarkDups.sam
15:45:05.080 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups3995242104878254518/MarkDups.sam done
15:45:05.080 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 3:45:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
15:45:05.085 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:05.085 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
15:45:05.086 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:45:05.086 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:45:05.086 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:45:05.086 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 3:45:05 PM UTC
15:45:05.086 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:05.086 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:05.086 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:45:05.086 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:45:05.086 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:45:05.086 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:45:05.086 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:45:05.086 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:45:05.086 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:45:05.086 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:45:05.086 INFO  MarkDuplicatesSpark - Initializing engine
15:45:05.086 INFO  MarkDuplicatesSpark - Done initializing engine
15:45:05.086 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:45:05.088 INFO  MemoryStore - Block broadcast_2062 stored as values in memory (estimated size 306.3 KiB, free 1909.4 MiB)
15:45:05.094 INFO  MemoryStore - Block broadcast_2062_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1909.4 MiB)
15:45:05.095 INFO  BlockManagerInfo - Added broadcast_2062_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1918.4 MiB)
15:45:05.095 INFO  SparkContext - Created broadcast 2062 from newAPIHadoopFile at PathSplitSource.java:96
15:45:05.115 INFO  MemoryStore - Block broadcast_2063 stored as values in memory (estimated size 306.3 KiB, free 1909.1 MiB)
15:45:05.126 INFO  MemoryStore - Block broadcast_2063_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1909.0 MiB)
15:45:05.126 INFO  BlockManagerInfo - Added broadcast_2063_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1918.3 MiB)
15:45:05.126 INFO  SparkContext - Created broadcast 2063 from newAPIHadoopFile at PathSplitSource.java:96
15:45:05.164 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:45:05.164 INFO  FileInputFormat - Total input files to process : 1
15:45:05.164 INFO  DAGScheduler - Registering RDD 5709 (mapToPair at SparkUtils.java:161) as input to shuffle 305
15:45:05.164 INFO  DAGScheduler - Got job 582 (collect at SparkUtils.java:205) with 1 output partitions
15:45:05.164 INFO  DAGScheduler - Final stage: ResultStage 1251 (collect at SparkUtils.java:205)
15:45:05.164 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1250)
15:45:05.165 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1250)
15:45:05.165 INFO  DAGScheduler - Submitting ShuffleMapStage 1250 (MapPartitionsRDD[5709] at mapToPair at SparkUtils.java:161), which has no missing parents
15:45:05.181 INFO  MemoryStore - Block broadcast_2064 stored as values in memory (estimated size 457.4 KiB, free 1908.6 MiB)
15:45:05.184 INFO  MemoryStore - Block broadcast_2064_piece0 stored as bytes in memory (estimated size 201.1 KiB, free 1908.4 MiB)
15:45:05.184 INFO  BlockManagerInfo - Added broadcast_2064_piece0 in memory on localhost:44421 (size: 201.1 KiB, free: 1918.1 MiB)
15:45:05.184 INFO  SparkContext - Created broadcast 2064 from broadcast at DAGScheduler.scala:1580
15:45:05.184 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1250 (MapPartitionsRDD[5709] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:45:05.184 INFO  TaskSchedulerImpl - Adding task set 1250.0 with 1 tasks resource profile 0
15:45:05.185 INFO  TaskSetManager - Starting task 0.0 in stage 1250.0 (TID 1090) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9738 bytes) 
15:45:05.185 INFO  Executor - Running task 0.0 in stage 1250.0 (TID 1090)
15:45:05.213 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam:0+678
15:45:05.216 INFO  Executor - Finished task 0.0 in stage 1250.0 (TID 1090). 1148 bytes result sent to driver
15:45:05.217 INFO  TaskSetManager - Finished task 0.0 in stage 1250.0 (TID 1090) in 33 ms on localhost (executor driver) (1/1)
15:45:05.217 INFO  TaskSchedulerImpl - Removed TaskSet 1250.0, whose tasks have all completed, from pool 
15:45:05.217 INFO  DAGScheduler - ShuffleMapStage 1250 (mapToPair at SparkUtils.java:161) finished in 0.052 s
15:45:05.217 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.217 INFO  DAGScheduler - running: HashSet()
15:45:05.217 INFO  DAGScheduler - waiting: HashSet(ResultStage 1251)
15:45:05.217 INFO  DAGScheduler - failed: HashSet()
15:45:05.217 INFO  DAGScheduler - Submitting ResultStage 1251 (MapPartitionsRDD[5712] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:45:05.217 INFO  MemoryStore - Block broadcast_2065 stored as values in memory (estimated size 7.4 KiB, free 1908.4 MiB)
15:45:05.218 INFO  MemoryStore - Block broadcast_2065_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1908.4 MiB)
15:45:05.218 INFO  BlockManagerInfo - Added broadcast_2065_piece0 in memory on localhost:44421 (size: 4.1 KiB, free: 1918.1 MiB)
15:45:05.218 INFO  SparkContext - Created broadcast 2065 from broadcast at DAGScheduler.scala:1580
15:45:05.218 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1251 (MapPartitionsRDD[5712] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:45:05.218 INFO  TaskSchedulerImpl - Adding task set 1251.0 with 1 tasks resource profile 0
15:45:05.219 INFO  TaskSetManager - Starting task 0.0 in stage 1251.0 (TID 1091) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:05.219 INFO  Executor - Running task 0.0 in stage 1251.0 (TID 1091)
15:45:05.220 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:45:05.220 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.221 INFO  Executor - Finished task 0.0 in stage 1251.0 (TID 1091). 2269 bytes result sent to driver
15:45:05.221 INFO  TaskSetManager - Finished task 0.0 in stage 1251.0 (TID 1091) in 2 ms on localhost (executor driver) (1/1)
15:45:05.221 INFO  TaskSchedulerImpl - Removed TaskSet 1251.0, whose tasks have all completed, from pool 
15:45:05.221 INFO  DAGScheduler - ResultStage 1251 (collect at SparkUtils.java:205) finished in 0.004 s
15:45:05.221 INFO  DAGScheduler - Job 582 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:05.222 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1251: Stage finished
15:45:05.222 INFO  DAGScheduler - Job 582 finished: collect at SparkUtils.java:205, took 0.058018 s
15:45:05.226 INFO  MemoryStore - Block broadcast_2066 stored as values in memory (estimated size 136.0 B, free 1908.4 MiB)
15:45:05.226 INFO  MemoryStore - Block broadcast_2066_piece0 stored as bytes in memory (estimated size 24.0 B, free 1908.4 MiB)
15:45:05.226 INFO  BlockManagerInfo - Added broadcast_2066_piece0 in memory on localhost:44421 (size: 24.0 B, free: 1918.1 MiB)
15:45:05.226 INFO  SparkContext - Created broadcast 2066 from broadcast at MarkDuplicatesSparkUtils.java:126
15:45:05.226 INFO  MemoryStore - Block broadcast_2067 stored as values in memory (estimated size 136.0 B, free 1908.4 MiB)
15:45:05.227 INFO  MemoryStore - Block broadcast_2067_piece0 stored as bytes in memory (estimated size 21.0 B, free 1908.4 MiB)
15:45:05.227 INFO  BlockManagerInfo - Added broadcast_2067_piece0 in memory on localhost:44421 (size: 21.0 B, free: 1918.1 MiB)
15:45:05.227 INFO  SparkContext - Created broadcast 2067 from broadcast at MarkDuplicatesSparkUtils.java:127
15:45:05.238 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:45:05.239 INFO  DAGScheduler - Registering RDD 5721 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 308
15:45:05.239 INFO  DAGScheduler - Registering RDD 5725 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 307
15:45:05.239 INFO  DAGScheduler - Registering RDD 5729 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 306
15:45:05.239 INFO  DAGScheduler - Got job 583 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:45:05.239 INFO  DAGScheduler - Final stage: ResultStage 1256 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:45:05.239 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1255)
15:45:05.239 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1255)
15:45:05.240 INFO  DAGScheduler - Submitting ShuffleMapStage 1253 (MapPartitionsRDD[5721] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:45:05.240 INFO  MemoryStore - Block broadcast_2068 stored as values in memory (estimated size 21.1 KiB, free 1908.3 MiB)
15:45:05.241 INFO  MemoryStore - Block broadcast_2068_piece0 stored as bytes in memory (estimated size 10.9 KiB, free 1908.3 MiB)
15:45:05.241 INFO  BlockManagerInfo - Added broadcast_2068_piece0 in memory on localhost:44421 (size: 10.9 KiB, free: 1918.1 MiB)
15:45:05.241 INFO  SparkContext - Created broadcast 2068 from broadcast at DAGScheduler.scala:1580
15:45:05.241 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1253 (MapPartitionsRDD[5721] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:45:05.241 INFO  TaskSchedulerImpl - Adding task set 1253.0 with 1 tasks resource profile 0
15:45:05.241 INFO  TaskSetManager - Starting task 0.0 in stage 1253.0 (TID 1092) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
15:45:05.242 INFO  Executor - Running task 0.0 in stage 1253.0 (TID 1092)
15:45:05.243 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:45:05.244 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.246 INFO  Executor - Finished task 0.0 in stage 1253.0 (TID 1092). 1922 bytes result sent to driver
15:45:05.246 INFO  TaskSetManager - Finished task 0.0 in stage 1253.0 (TID 1092) in 5 ms on localhost (executor driver) (1/1)
15:45:05.246 INFO  TaskSchedulerImpl - Removed TaskSet 1253.0, whose tasks have all completed, from pool 
15:45:05.246 INFO  DAGScheduler - ShuffleMapStage 1253 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.006 s
15:45:05.246 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.246 INFO  DAGScheduler - running: HashSet()
15:45:05.246 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1254, ShuffleMapStage 1255, ResultStage 1256)
15:45:05.246 INFO  DAGScheduler - failed: HashSet()
15:45:05.246 INFO  DAGScheduler - Submitting ShuffleMapStage 1254 (MapPartitionsRDD[5725] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:45:05.247 INFO  MemoryStore - Block broadcast_2069 stored as values in memory (estimated size 25.2 KiB, free 1908.3 MiB)
15:45:05.247 INFO  MemoryStore - Block broadcast_2069_piece0 stored as bytes in memory (estimated size 13.1 KiB, free 1908.3 MiB)
15:45:05.247 INFO  BlockManagerInfo - Added broadcast_2069_piece0 in memory on localhost:44421 (size: 13.1 KiB, free: 1918.1 MiB)
15:45:05.247 INFO  SparkContext - Created broadcast 2069 from broadcast at DAGScheduler.scala:1580
15:45:05.248 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1254 (MapPartitionsRDD[5725] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:45:05.248 INFO  TaskSchedulerImpl - Adding task set 1254.0 with 1 tasks resource profile 0
15:45:05.248 INFO  TaskSetManager - Starting task 0.0 in stage 1254.0 (TID 1093) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
15:45:05.248 INFO  Executor - Running task 0.0 in stage 1254.0 (TID 1093)
15:45:05.249 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:45:05.249 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.252 INFO  Executor - Finished task 0.0 in stage 1254.0 (TID 1093). 1879 bytes result sent to driver
15:45:05.252 INFO  TaskSetManager - Finished task 0.0 in stage 1254.0 (TID 1093) in 4 ms on localhost (executor driver) (1/1)
15:45:05.252 INFO  TaskSchedulerImpl - Removed TaskSet 1254.0, whose tasks have all completed, from pool 
15:45:05.253 INFO  DAGScheduler - ShuffleMapStage 1254 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
15:45:05.253 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.253 INFO  DAGScheduler - running: HashSet()
15:45:05.253 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1255, ResultStage 1256)
15:45:05.253 INFO  DAGScheduler - failed: HashSet()
15:45:05.253 INFO  DAGScheduler - Submitting ShuffleMapStage 1255 (MapPartitionsRDD[5729] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:45:05.253 INFO  MemoryStore - Block broadcast_2070 stored as values in memory (estimated size 15.9 KiB, free 1908.3 MiB)
15:45:05.254 INFO  MemoryStore - Block broadcast_2070_piece0 stored as bytes in memory (estimated size 8.3 KiB, free 1908.3 MiB)
15:45:05.254 INFO  BlockManagerInfo - Added broadcast_2070_piece0 in memory on localhost:44421 (size: 8.3 KiB, free: 1918.1 MiB)
15:45:05.254 INFO  SparkContext - Created broadcast 2070 from broadcast at DAGScheduler.scala:1580
15:45:05.254 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1255 (MapPartitionsRDD[5729] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:45:05.254 INFO  TaskSchedulerImpl - Adding task set 1255.0 with 1 tasks resource profile 0
15:45:05.254 INFO  TaskSetManager - Starting task 0.0 in stage 1255.0 (TID 1094) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:45:05.255 INFO  Executor - Running task 0.0 in stage 1255.0 (TID 1094)
15:45:05.256 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:45:05.256 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.257 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:45:05.257 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.258 INFO  Executor - Finished task 0.0 in stage 1255.0 (TID 1094). 1879 bytes result sent to driver
15:45:05.258 INFO  TaskSetManager - Finished task 0.0 in stage 1255.0 (TID 1094) in 4 ms on localhost (executor driver) (1/1)
15:45:05.258 INFO  TaskSchedulerImpl - Removed TaskSet 1255.0, whose tasks have all completed, from pool 
15:45:05.258 INFO  DAGScheduler - ShuffleMapStage 1255 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.005 s
15:45:05.258 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.258 INFO  DAGScheduler - running: HashSet()
15:45:05.258 INFO  DAGScheduler - waiting: HashSet(ResultStage 1256)
15:45:05.258 INFO  DAGScheduler - failed: HashSet()
15:45:05.258 INFO  DAGScheduler - Submitting ResultStage 1256 (MapPartitionsRDD[5731] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:45:05.259 INFO  MemoryStore - Block broadcast_2071 stored as values in memory (estimated size 17.1 KiB, free 1908.3 MiB)
15:45:05.259 INFO  MemoryStore - Block broadcast_2071_piece0 stored as bytes in memory (estimated size 9.0 KiB, free 1908.2 MiB)
15:45:05.260 INFO  BlockManagerInfo - Added broadcast_2071_piece0 in memory on localhost:44421 (size: 9.0 KiB, free: 1918.1 MiB)
15:45:05.260 INFO  SparkContext - Created broadcast 2071 from broadcast at DAGScheduler.scala:1580
15:45:05.260 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1256 (MapPartitionsRDD[5731] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:45:05.260 INFO  TaskSchedulerImpl - Adding task set 1256.0 with 1 tasks resource profile 0
15:45:05.260 INFO  TaskSetManager - Starting task 0.0 in stage 1256.0 (TID 1095) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:05.260 INFO  Executor - Running task 0.0 in stage 1256.0 (TID 1095)
15:45:05.261 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:45:05.261 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.263 INFO  Executor - Finished task 0.0 in stage 1256.0 (TID 1095). 1887 bytes result sent to driver
15:45:05.263 INFO  TaskSetManager - Finished task 0.0 in stage 1256.0 (TID 1095) in 3 ms on localhost (executor driver) (1/1)
15:45:05.263 INFO  TaskSchedulerImpl - Removed TaskSet 1256.0, whose tasks have all completed, from pool 
15:45:05.263 INFO  DAGScheduler - ResultStage 1256 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.004 s
15:45:05.263 INFO  DAGScheduler - Job 583 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:05.263 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1256: Stage finished
15:45:05.263 INFO  DAGScheduler - Job 583 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.024629 s
15:45:05.273 INFO  MemoryStore - Block broadcast_2072 stored as values in memory (estimated size 5.6 KiB, free 1908.2 MiB)
15:45:05.273 INFO  MemoryStore - Block broadcast_2072_piece0 stored as bytes in memory (estimated size 500.0 B, free 1908.2 MiB)
15:45:05.273 INFO  BlockManagerInfo - Added broadcast_2072_piece0 in memory on localhost:44421 (size: 500.0 B, free: 1918.1 MiB)
15:45:05.273 INFO  SparkContext - Created broadcast 2072 from broadcast at ReadsSparkSink.java:133
15:45:05.277 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:45:05.277 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:45:05.277 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:45:05.293 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:45:05.293 INFO  DAGScheduler - Registering RDD 5733 (mapToPair at SparkUtils.java:161) as input to shuffle 309
15:45:05.293 INFO  DAGScheduler - Got job 584 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:45:05.293 INFO  DAGScheduler - Final stage: ResultStage 1261 (runJob at SparkHadoopWriter.scala:83)
15:45:05.293 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1260)
15:45:05.293 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1260)
15:45:05.293 INFO  DAGScheduler - Submitting ShuffleMapStage 1260 (MapPartitionsRDD[5733] at mapToPair at SparkUtils.java:161), which has no missing parents
15:45:05.294 INFO  MemoryStore - Block broadcast_2073 stored as values in memory (estimated size 15.0 KiB, free 1908.2 MiB)
15:45:05.294 INFO  MemoryStore - Block broadcast_2073_piece0 stored as bytes in memory (estimated size 7.8 KiB, free 1908.2 MiB)
15:45:05.294 INFO  BlockManagerInfo - Added broadcast_2073_piece0 in memory on localhost:44421 (size: 7.8 KiB, free: 1918.1 MiB)
15:45:05.294 INFO  SparkContext - Created broadcast 2073 from broadcast at DAGScheduler.scala:1580
15:45:05.295 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1260 (MapPartitionsRDD[5733] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:45:05.295 INFO  TaskSchedulerImpl - Adding task set 1260.0 with 1 tasks resource profile 0
15:45:05.295 INFO  TaskSetManager - Starting task 0.0 in stage 1260.0 (TID 1096) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:45:05.295 INFO  Executor - Running task 0.0 in stage 1260.0 (TID 1096)
15:45:05.296 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:45:05.296 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.298 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:45:05.298 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.299 INFO  Executor - Finished task 0.0 in stage 1260.0 (TID 1096). 1879 bytes result sent to driver
15:45:05.299 INFO  TaskSetManager - Finished task 0.0 in stage 1260.0 (TID 1096) in 4 ms on localhost (executor driver) (1/1)
15:45:05.299 INFO  TaskSchedulerImpl - Removed TaskSet 1260.0, whose tasks have all completed, from pool 
15:45:05.299 INFO  DAGScheduler - ShuffleMapStage 1260 (mapToPair at SparkUtils.java:161) finished in 0.006 s
15:45:05.299 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.299 INFO  DAGScheduler - running: HashSet()
15:45:05.299 INFO  DAGScheduler - waiting: HashSet(ResultStage 1261)
15:45:05.299 INFO  DAGScheduler - failed: HashSet()
15:45:05.299 INFO  DAGScheduler - Submitting ResultStage 1261 (MapPartitionsRDD[5739] at saveAsTextFile at SamSink.java:65), which has no missing parents
15:45:05.305 INFO  MemoryStore - Block broadcast_2074 stored as values in memory (estimated size 160.3 KiB, free 1908.1 MiB)
15:45:05.306 INFO  MemoryStore - Block broadcast_2074_piece0 stored as bytes in memory (estimated size 72.1 KiB, free 1908.0 MiB)
15:45:05.306 INFO  BlockManagerInfo - Added broadcast_2074_piece0 in memory on localhost:44421 (size: 72.1 KiB, free: 1918.0 MiB)
15:45:05.306 INFO  SparkContext - Created broadcast 2074 from broadcast at DAGScheduler.scala:1580
15:45:05.307 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1261 (MapPartitionsRDD[5739] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
15:45:05.307 INFO  TaskSchedulerImpl - Adding task set 1261.0 with 1 tasks resource profile 0
15:45:05.307 INFO  TaskSetManager - Starting task 0.0 in stage 1261.0 (TID 1097) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:05.307 INFO  Executor - Running task 0.0 in stage 1261.0 (TID 1097)
15:45:05.310 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:45:05.310 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.311 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:45:05.311 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:45:05.311 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:45:05.322 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191545054210686211100870093_5739_m_000000_0' to file:/tmp/MarkDups16937425571867320917/MarkDups.sam.parts/_temporary/0/task_202505191545054210686211100870093_5739_m_000000
15:45:05.322 INFO  SparkHadoopMapRedUtil - attempt_202505191545054210686211100870093_5739_m_000000_0: Committed. Elapsed time: 0 ms.
15:45:05.322 INFO  Executor - Finished task 0.0 in stage 1261.0 (TID 1097). 1858 bytes result sent to driver
15:45:05.322 INFO  TaskSetManager - Finished task 0.0 in stage 1261.0 (TID 1097) in 15 ms on localhost (executor driver) (1/1)
15:45:05.322 INFO  TaskSchedulerImpl - Removed TaskSet 1261.0, whose tasks have all completed, from pool 
15:45:05.322 INFO  DAGScheduler - ResultStage 1261 (runJob at SparkHadoopWriter.scala:83) finished in 0.023 s
15:45:05.323 INFO  DAGScheduler - Job 584 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:05.323 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1261: Stage finished
15:45:05.323 INFO  DAGScheduler - Job 584 finished: runJob at SparkHadoopWriter.scala:83, took 0.029928 s
15:45:05.323 INFO  SparkHadoopWriter - Start to commit write Job job_202505191545054210686211100870093_5739.
15:45:05.327 INFO  SparkHadoopWriter - Write Job job_202505191545054210686211100870093_5739 committed. Elapsed time: 3 ms.
15:45:05.333 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups16937425571867320917/MarkDups.sam
15:45:05.337 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups16937425571867320917/MarkDups.sam done
15:45:05.337 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 3:45:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
15:45:05.342 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:05.342 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
15:45:05.342 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
15:45:05.342 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:45:05.342 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:45:05.342 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 3:45:05 PM UTC
15:45:05.342 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:05.342 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
15:45:05.342 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:45:05.342 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:45:05.342 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:45:05.342 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:45:05.342 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
15:45:05.342 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
15:45:05.342 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
15:45:05.342 INFO  MarkDuplicatesSpark - Requester pays: disabled
15:45:05.342 INFO  MarkDuplicatesSpark - Initializing engine
15:45:05.342 INFO  MarkDuplicatesSpark - Done initializing engine
15:45:05.342 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
15:45:05.345 INFO  MemoryStore - Block broadcast_2075 stored as values in memory (estimated size 306.3 KiB, free 1907.7 MiB)
15:45:05.351 INFO  MemoryStore - Block broadcast_2075_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1907.6 MiB)
15:45:05.351 INFO  BlockManagerInfo - Added broadcast_2075_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1917.9 MiB)
15:45:05.351 INFO  SparkContext - Created broadcast 2075 from newAPIHadoopFile at PathSplitSource.java:96
15:45:05.371 INFO  MemoryStore - Block broadcast_2076 stored as values in memory (estimated size 306.3 KiB, free 1907.3 MiB)
15:45:05.377 INFO  MemoryStore - Block broadcast_2076_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1907.3 MiB)
15:45:05.377 INFO  BlockManagerInfo - Added broadcast_2076_piece0 in memory on localhost:44421 (size: 64.4 KiB, free: 1917.9 MiB)
15:45:05.377 INFO  SparkContext - Created broadcast 2076 from newAPIHadoopFile at PathSplitSource.java:96
15:45:05.409 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
15:45:05.410 INFO  FileInputFormat - Total input files to process : 1
15:45:05.410 INFO  DAGScheduler - Registering RDD 5753 (mapToPair at SparkUtils.java:161) as input to shuffle 310
15:45:05.410 INFO  DAGScheduler - Got job 585 (collect at SparkUtils.java:205) with 1 output partitions
15:45:05.410 INFO  DAGScheduler - Final stage: ResultStage 1263 (collect at SparkUtils.java:205)
15:45:05.410 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1262)
15:45:05.410 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1262)
15:45:05.410 INFO  DAGScheduler - Submitting ShuffleMapStage 1262 (MapPartitionsRDD[5753] at mapToPair at SparkUtils.java:161), which has no missing parents
15:45:05.427 INFO  MemoryStore - Block broadcast_2077 stored as values in memory (estimated size 481.4 KiB, free 1906.8 MiB)
15:45:05.430 INFO  MemoryStore - Block broadcast_2077_piece0 stored as bytes in memory (estimated size 207.4 KiB, free 1906.6 MiB)
15:45:05.430 INFO  BlockManagerInfo - Added broadcast_2077_piece0 in memory on localhost:44421 (size: 207.4 KiB, free: 1917.7 MiB)
15:45:05.430 INFO  SparkContext - Created broadcast 2077 from broadcast at DAGScheduler.scala:1580
15:45:05.430 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1262 (MapPartitionsRDD[5753] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:45:05.430 INFO  TaskSchedulerImpl - Adding task set 1262.0 with 1 tasks resource profile 0
15:45:05.430 INFO  TaskSetManager - Starting task 0.0 in stage 1262.0 (TID 1098) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9757 bytes) 
15:45:05.431 INFO  Executor - Running task 0.0 in stage 1262.0 (TID 1098)
15:45:05.458 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam:0+5416
15:45:05.463 INFO  Executor - Finished task 0.0 in stage 1262.0 (TID 1098). 1148 bytes result sent to driver
15:45:05.463 INFO  TaskSetManager - Finished task 0.0 in stage 1262.0 (TID 1098) in 33 ms on localhost (executor driver) (1/1)
15:45:05.463 INFO  TaskSchedulerImpl - Removed TaskSet 1262.0, whose tasks have all completed, from pool 
15:45:05.463 INFO  DAGScheduler - ShuffleMapStage 1262 (mapToPair at SparkUtils.java:161) finished in 0.052 s
15:45:05.463 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.463 INFO  DAGScheduler - running: HashSet()
15:45:05.463 INFO  DAGScheduler - waiting: HashSet(ResultStage 1263)
15:45:05.463 INFO  DAGScheduler - failed: HashSet()
15:45:05.464 INFO  DAGScheduler - Submitting ResultStage 1263 (MapPartitionsRDD[5756] at mapPartitions at SparkUtils.java:188), which has no missing parents
15:45:05.464 INFO  MemoryStore - Block broadcast_2078 stored as values in memory (estimated size 7.4 KiB, free 1906.6 MiB)
15:45:05.464 INFO  MemoryStore - Block broadcast_2078_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1906.6 MiB)
15:45:05.464 INFO  BlockManagerInfo - Added broadcast_2078_piece0 in memory on localhost:44421 (size: 4.1 KiB, free: 1917.7 MiB)
15:45:05.465 INFO  SparkContext - Created broadcast 2078 from broadcast at DAGScheduler.scala:1580
15:45:05.465 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1263 (MapPartitionsRDD[5756] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
15:45:05.465 INFO  TaskSchedulerImpl - Adding task set 1263.0 with 1 tasks resource profile 0
15:45:05.465 INFO  TaskSetManager - Starting task 0.0 in stage 1263.0 (TID 1099) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:05.465 INFO  Executor - Running task 0.0 in stage 1263.0 (TID 1099)
15:45:05.466 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:45:05.466 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.467 INFO  Executor - Finished task 0.0 in stage 1263.0 (TID 1099). 2039 bytes result sent to driver
15:45:05.468 INFO  TaskSetManager - Finished task 0.0 in stage 1263.0 (TID 1099) in 3 ms on localhost (executor driver) (1/1)
15:45:05.468 INFO  TaskSchedulerImpl - Removed TaskSet 1263.0, whose tasks have all completed, from pool 
15:45:05.468 INFO  DAGScheduler - ResultStage 1263 (collect at SparkUtils.java:205) finished in 0.004 s
15:45:05.468 INFO  DAGScheduler - Job 585 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:05.468 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1263: Stage finished
15:45:05.468 INFO  DAGScheduler - Job 585 finished: collect at SparkUtils.java:205, took 0.058600 s
15:45:05.472 INFO  MemoryStore - Block broadcast_2079 stored as values in memory (estimated size 392.0 B, free 1906.6 MiB)
15:45:05.472 INFO  MemoryStore - Block broadcast_2079_piece0 stored as bytes in memory (estimated size 33.0 B, free 1906.6 MiB)
15:45:05.472 INFO  BlockManagerInfo - Added broadcast_2079_piece0 in memory on localhost:44421 (size: 33.0 B, free: 1917.7 MiB)
15:45:05.472 INFO  SparkContext - Created broadcast 2079 from broadcast at MarkDuplicatesSparkUtils.java:126
15:45:05.473 INFO  MemoryStore - Block broadcast_2080 stored as values in memory (estimated size 144.0 B, free 1906.6 MiB)
15:45:05.473 INFO  MemoryStore - Block broadcast_2080_piece0 stored as bytes in memory (estimated size 28.0 B, free 1906.6 MiB)
15:45:05.473 INFO  BlockManagerInfo - Added broadcast_2080_piece0 in memory on localhost:44421 (size: 28.0 B, free: 1917.7 MiB)
15:45:05.473 INFO  SparkContext - Created broadcast 2080 from broadcast at MarkDuplicatesSparkUtils.java:127
15:45:05.486 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
15:45:05.486 INFO  DAGScheduler - Registering RDD 5765 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 313
15:45:05.486 INFO  DAGScheduler - Registering RDD 5769 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 312
15:45:05.486 INFO  DAGScheduler - Registering RDD 5773 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 311
15:45:05.486 INFO  DAGScheduler - Got job 586 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
15:45:05.486 INFO  DAGScheduler - Final stage: ResultStage 1268 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
15:45:05.487 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1267)
15:45:05.487 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1267)
15:45:05.487 INFO  DAGScheduler - Submitting ShuffleMapStage 1265 (MapPartitionsRDD[5765] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
15:45:05.487 INFO  MemoryStore - Block broadcast_2081 stored as values in memory (estimated size 45.2 KiB, free 1906.5 MiB)
15:45:05.488 INFO  MemoryStore - Block broadcast_2081_piece0 stored as bytes in memory (estimated size 17.1 KiB, free 1906.5 MiB)
15:45:05.488 INFO  BlockManagerInfo - Added broadcast_2081_piece0 in memory on localhost:44421 (size: 17.1 KiB, free: 1917.7 MiB)
15:45:05.488 INFO  SparkContext - Created broadcast 2081 from broadcast at DAGScheduler.scala:1580
15:45:05.488 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1265 (MapPartitionsRDD[5765] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
15:45:05.488 INFO  TaskSchedulerImpl - Adding task set 1265.0 with 1 tasks resource profile 0
15:45:05.489 INFO  TaskSetManager - Starting task 0.0 in stage 1265.0 (TID 1100) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
15:45:05.489 INFO  Executor - Running task 0.0 in stage 1265.0 (TID 1100)
15:45:05.490 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:45:05.490 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.493 INFO  Executor - Finished task 0.0 in stage 1265.0 (TID 1100). 1922 bytes result sent to driver
15:45:05.493 INFO  TaskSetManager - Finished task 0.0 in stage 1265.0 (TID 1100) in 4 ms on localhost (executor driver) (1/1)
15:45:05.493 INFO  TaskSchedulerImpl - Removed TaskSet 1265.0, whose tasks have all completed, from pool 
15:45:05.493 INFO  DAGScheduler - ShuffleMapStage 1265 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.006 s
15:45:05.493 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.493 INFO  DAGScheduler - running: HashSet()
15:45:05.493 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1266, ShuffleMapStage 1267, ResultStage 1268)
15:45:05.493 INFO  DAGScheduler - failed: HashSet()
15:45:05.493 INFO  DAGScheduler - Submitting ShuffleMapStage 1266 (MapPartitionsRDD[5769] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
15:45:05.494 INFO  MemoryStore - Block broadcast_2082 stored as values in memory (estimated size 49.3 KiB, free 1906.5 MiB)
15:45:05.495 INFO  MemoryStore - Block broadcast_2082_piece0 stored as bytes in memory (estimated size 19.3 KiB, free 1906.5 MiB)
15:45:05.495 INFO  BlockManagerInfo - Added broadcast_2082_piece0 in memory on localhost:44421 (size: 19.3 KiB, free: 1917.6 MiB)
15:45:05.495 INFO  SparkContext - Created broadcast 2082 from broadcast at DAGScheduler.scala:1580
15:45:05.495 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1266 (MapPartitionsRDD[5769] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
15:45:05.495 INFO  TaskSchedulerImpl - Adding task set 1266.0 with 1 tasks resource profile 0
15:45:05.495 INFO  TaskSetManager - Starting task 0.0 in stage 1266.0 (TID 1101) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
15:45:05.495 INFO  Executor - Running task 0.0 in stage 1266.0 (TID 1101)
15:45:05.497 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:45:05.497 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.501 INFO  Executor - Finished task 0.0 in stage 1266.0 (TID 1101). 1922 bytes result sent to driver
15:45:05.501 INFO  TaskSetManager - Finished task 0.0 in stage 1266.0 (TID 1101) in 6 ms on localhost (executor driver) (1/1)
15:45:05.502 INFO  TaskSchedulerImpl - Removed TaskSet 1266.0, whose tasks have all completed, from pool 
15:45:05.502 INFO  DAGScheduler - ShuffleMapStage 1266 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.008 s
15:45:05.502 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.502 INFO  DAGScheduler - running: HashSet()
15:45:05.502 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1267, ResultStage 1268)
15:45:05.502 INFO  DAGScheduler - failed: HashSet()
15:45:05.502 INFO  DAGScheduler - Submitting ShuffleMapStage 1267 (MapPartitionsRDD[5773] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
15:45:05.503 INFO  MemoryStore - Block broadcast_2083 stored as values in memory (estimated size 40.0 KiB, free 1906.4 MiB)
15:45:05.503 INFO  MemoryStore - Block broadcast_2083_piece0 stored as bytes in memory (estimated size 14.5 KiB, free 1906.4 MiB)
15:45:05.503 INFO  BlockManagerInfo - Added broadcast_2083_piece0 in memory on localhost:44421 (size: 14.5 KiB, free: 1917.6 MiB)
15:45:05.503 INFO  SparkContext - Created broadcast 2083 from broadcast at DAGScheduler.scala:1580
15:45:05.504 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1267 (MapPartitionsRDD[5773] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
15:45:05.504 INFO  TaskSchedulerImpl - Adding task set 1267.0 with 1 tasks resource profile 0
15:45:05.504 INFO  TaskSetManager - Starting task 0.0 in stage 1267.0 (TID 1102) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:45:05.504 INFO  Executor - Running task 0.0 in stage 1267.0 (TID 1102)
15:45:05.505 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:45:05.505 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.507 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:45:05.507 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.508 INFO  Executor - Finished task 0.0 in stage 1267.0 (TID 1102). 1922 bytes result sent to driver
15:45:05.508 INFO  TaskSetManager - Finished task 0.0 in stage 1267.0 (TID 1102) in 4 ms on localhost (executor driver) (1/1)
15:45:05.508 INFO  TaskSchedulerImpl - Removed TaskSet 1267.0, whose tasks have all completed, from pool 
15:45:05.508 INFO  DAGScheduler - ShuffleMapStage 1267 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
15:45:05.508 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.508 INFO  DAGScheduler - running: HashSet()
15:45:05.508 INFO  DAGScheduler - waiting: HashSet(ResultStage 1268)
15:45:05.508 INFO  DAGScheduler - failed: HashSet()
15:45:05.508 INFO  DAGScheduler - Submitting ResultStage 1268 (MapPartitionsRDD[5775] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
15:45:05.509 INFO  MemoryStore - Block broadcast_2084 stored as values in memory (estimated size 41.2 KiB, free 1906.4 MiB)
15:45:05.509 INFO  MemoryStore - Block broadcast_2084_piece0 stored as bytes in memory (estimated size 15.3 KiB, free 1906.3 MiB)
15:45:05.509 INFO  BlockManagerInfo - Added broadcast_2084_piece0 in memory on localhost:44421 (size: 15.3 KiB, free: 1917.6 MiB)
15:45:05.510 INFO  SparkContext - Created broadcast 2084 from broadcast at DAGScheduler.scala:1580
15:45:05.510 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1268 (MapPartitionsRDD[5775] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
15:45:05.510 INFO  TaskSchedulerImpl - Adding task set 1268.0 with 1 tasks resource profile 0
15:45:05.510 INFO  TaskSetManager - Starting task 0.0 in stage 1268.0 (TID 1103) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:05.510 INFO  Executor - Running task 0.0 in stage 1268.0 (TID 1103)
15:45:05.511 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:45:05.511 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.512 INFO  Executor - Finished task 0.0 in stage 1268.0 (TID 1103). 1901 bytes result sent to driver
15:45:05.513 INFO  TaskSetManager - Finished task 0.0 in stage 1268.0 (TID 1103) in 3 ms on localhost (executor driver) (1/1)
15:45:05.513 INFO  TaskSchedulerImpl - Removed TaskSet 1268.0, whose tasks have all completed, from pool 
15:45:05.513 INFO  DAGScheduler - ResultStage 1268 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
15:45:05.513 INFO  DAGScheduler - Job 586 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:05.513 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1268: Stage finished
15:45:05.513 INFO  DAGScheduler - Job 586 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.027098 s
15:45:05.524 INFO  MemoryStore - Block broadcast_2085 stored as values in memory (estimated size 93.5 KiB, free 1906.3 MiB)
15:45:05.524 INFO  MemoryStore - Block broadcast_2085_piece0 stored as bytes in memory (estimated size 5.6 KiB, free 1906.2 MiB)
15:45:05.524 INFO  BlockManagerInfo - Added broadcast_2085_piece0 in memory on localhost:44421 (size: 5.6 KiB, free: 1917.6 MiB)
15:45:05.524 INFO  SparkContext - Created broadcast 2085 from broadcast at ReadsSparkSink.java:133
15:45:05.528 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:45:05.528 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:45:05.528 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:45:05.544 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
15:45:05.544 INFO  DAGScheduler - Registering RDD 5777 (mapToPair at SparkUtils.java:161) as input to shuffle 314
15:45:05.544 INFO  DAGScheduler - Got job 587 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
15:45:05.544 INFO  DAGScheduler - Final stage: ResultStage 1273 (runJob at SparkHadoopWriter.scala:83)
15:45:05.544 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1272)
15:45:05.544 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1272)
15:45:05.544 INFO  DAGScheduler - Submitting ShuffleMapStage 1272 (MapPartitionsRDD[5777] at mapToPair at SparkUtils.java:161), which has no missing parents
15:45:05.545 INFO  MemoryStore - Block broadcast_2086 stored as values in memory (estimated size 39.1 KiB, free 1906.2 MiB)
15:45:05.545 INFO  MemoryStore - Block broadcast_2086_piece0 stored as bytes in memory (estimated size 14.1 KiB, free 1906.2 MiB)
15:45:05.546 INFO  BlockManagerInfo - Added broadcast_2086_piece0 in memory on localhost:44421 (size: 14.1 KiB, free: 1917.6 MiB)
15:45:05.546 INFO  SparkContext - Created broadcast 2086 from broadcast at DAGScheduler.scala:1580
15:45:05.546 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1272 (MapPartitionsRDD[5777] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
15:45:05.546 INFO  TaskSchedulerImpl - Adding task set 1272.0 with 1 tasks resource profile 0
15:45:05.546 INFO  TaskSetManager - Starting task 0.0 in stage 1272.0 (TID 1104) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
15:45:05.546 INFO  Executor - Running task 0.0 in stage 1272.0 (TID 1104)
15:45:05.548 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:45:05.548 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.549 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:45:05.549 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.550 INFO  Executor - Finished task 0.0 in stage 1272.0 (TID 1104). 1922 bytes result sent to driver
15:45:05.550 INFO  TaskSetManager - Finished task 0.0 in stage 1272.0 (TID 1104) in 4 ms on localhost (executor driver) (1/1)
15:45:05.551 INFO  TaskSchedulerImpl - Removed TaskSet 1272.0, whose tasks have all completed, from pool 
15:45:05.551 INFO  DAGScheduler - ShuffleMapStage 1272 (mapToPair at SparkUtils.java:161) finished in 0.007 s
15:45:05.551 INFO  DAGScheduler - looking for newly runnable stages
15:45:05.551 INFO  DAGScheduler - running: HashSet()
15:45:05.551 INFO  DAGScheduler - waiting: HashSet(ResultStage 1273)
15:45:05.551 INFO  DAGScheduler - failed: HashSet()
15:45:05.551 INFO  DAGScheduler - Submitting ResultStage 1273 (MapPartitionsRDD[5783] at saveAsTextFile at SamSink.java:65), which has no missing parents
15:45:05.557 INFO  MemoryStore - Block broadcast_2087 stored as values in memory (estimated size 184.3 KiB, free 1906.0 MiB)
15:45:05.558 INFO  MemoryStore - Block broadcast_2087_piece0 stored as bytes in memory (estimated size 78.3 KiB, free 1905.9 MiB)
15:45:05.558 INFO  BlockManagerInfo - Added broadcast_2087_piece0 in memory on localhost:44421 (size: 78.3 KiB, free: 1917.5 MiB)
15:45:05.558 INFO  SparkContext - Created broadcast 2087 from broadcast at DAGScheduler.scala:1580
15:45:05.558 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1273 (MapPartitionsRDD[5783] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
15:45:05.558 INFO  TaskSchedulerImpl - Adding task set 1273.0 with 1 tasks resource profile 0
15:45:05.559 INFO  TaskSetManager - Starting task 0.0 in stage 1273.0 (TID 1105) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
15:45:05.559 INFO  Executor - Running task 0.0 in stage 1273.0 (TID 1105)
15:45:05.562 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:45:05.562 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
15:45:05.564 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
15:45:05.564 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
15:45:05.564 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
15:45:05.574 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191545052163338885892204469_5783_m_000000_0' to file:/tmp/MarkDups5946888352907619918/MarkDups.sam.parts/_temporary/0/task_202505191545052163338885892204469_5783_m_000000
15:45:05.574 INFO  SparkHadoopMapRedUtil - attempt_202505191545052163338885892204469_5783_m_000000_0: Committed. Elapsed time: 0 ms.
15:45:05.574 INFO  Executor - Finished task 0.0 in stage 1273.0 (TID 1105). 1858 bytes result sent to driver
15:45:05.575 INFO  TaskSetManager - Finished task 0.0 in stage 1273.0 (TID 1105) in 16 ms on localhost (executor driver) (1/1)
15:45:05.575 INFO  TaskSchedulerImpl - Removed TaskSet 1273.0, whose tasks have all completed, from pool 
15:45:05.575 INFO  DAGScheduler - ResultStage 1273 (runJob at SparkHadoopWriter.scala:83) finished in 0.024 s
15:45:05.575 INFO  DAGScheduler - Job 587 is finished. Cancelling potential speculative or zombie tasks for this job
15:45:05.575 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1273: Stage finished
15:45:05.575 INFO  DAGScheduler - Job 587 finished: runJob at SparkHadoopWriter.scala:83, took 0.031234 s
15:45:05.575 INFO  SparkHadoopWriter - Start to commit write Job job_202505191545052163338885892204469_5783.
15:45:05.579 INFO  SparkHadoopWriter - Write Job job_202505191545052163338885892204469_5783 committed. Elapsed time: 3 ms.
15:45:05.586 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups5946888352907619918/MarkDups.sam
15:45:05.589 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups5946888352907619918/MarkDups.sam done
15:45:05.589 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 3:45:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:06 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:06 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:06 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:07 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:07 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:07 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:09 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:09 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:09 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:10 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:10 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:10 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:11 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
15:45:11.260 ERROR Executor - Exception in task 0.0 in stage 1493.0 (TID 1252)
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) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[main/:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[main/:?]
	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) ~[main/:?]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[scala-library-2.13.14.jar:?]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[scala-library-2.13.14.jar:?]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [spark-core_2.13-3.5.0.jar:3.5.0]
	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:833) [?:?]
15:45:11.274 ERROR TaskSetManager - Task 0 in stage 1493.0 failed 1 times; aborting job
[May 19, 2025 at 3:45:11 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
15:45:11.496 ERROR Executor - Exception in task 0.0 in stage 1500.0 (TID 1255)
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) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[main/:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[main/:?]
	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) ~[main/:?]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[scala-library-2.13.14.jar:?]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[scala-library-2.13.14.jar:?]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [spark-core_2.13-3.5.0.jar:3.5.0]
	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:833) [?:?]
15:45:11.498 ERROR TaskSetManager - Task 0 in stage 1500.0 failed 1 times; aborting job
[May 19, 2025 at 3:45:11 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:11 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:13 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:13 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:13 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:14 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:14 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:14 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:16 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:16 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:16 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:17 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:17 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:17 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:18 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:18 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:18 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:19 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:19 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:19 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:19 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:20 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:20 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:20 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:21 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:21 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:21 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:22 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:22 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:22 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:22 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:23 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:23 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:23 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:24 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:24 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:24 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:25 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:25 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:25 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:25 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:26 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:26 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:26 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:28 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:28 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:28 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:29 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:29 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:29 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:31 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:31 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:31 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:32 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:32 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:32 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:34 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:34 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:34 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:35 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:35 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288
[May 19, 2025 at 3:45:35 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=2032140288