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

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

tests
0

failures
0

ignored
58.715s

duration
100%

successful

Tests

Test Duration Result
assertThatExpectedOutputUpdateToggleIsDisabled 0s passed
testAssertAssumeUnsortedFilesAreQueryGroupedFiles 0.561s passed
testAssertCorrectSortOrderMultipleBams 0.139s passed
testAssertCorrectSortOrderMultipleBamsOverriding 0.480s passed
testBulkFragmentsNoDuplicates 0.913s passed
testBulkFragmentsWithDuplicates 2.107s passed
testDifferentChromosomesInOppositeOrder 0.294s 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.278s 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.233s 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.243s passed
testFlowModeFlag 1.564s passed
testHashCollisionHandling 1.029s 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.287s 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.276s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[0](true, true, true) 0.305s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[1](true, false, true) 0.312s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[2](false, true, true) 0.299s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[3](true, true, false) 0.299s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[4](true, false, false) 0.290s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[5](false, true, false) 0.306s passed
testMappedFragmentAndMappedPairFirstOfPairNonPrimary 0.310s passed
testMappedFragmentAndMatePairFirstUnmapped 0.304s passed
testMappedFragmentAndMatePairSecondUnmapped 0.296s passed
testMappedPairAndMappedFragmentAndMatePairFirstUnmapped 0.294s passed
testMappedPairAndMappedFragmentAndMatePairSecondUnmapped 0.318s passed
testMappedPairAndMatePairFirstOppositeStrandSecondUnmapped 0.303s passed
testMappedPairAndMatePairFirstUnmapped 0.287s passed
testMappedPairAndMatePairSecondUnmapped 0.293s passed
testMappedPairWithFirstEndSamePositionAndOther 0.305s passed
testMappedPairWithSamePosition 0.292s passed
testMappedPairWithSamePositionSameCigar 0.295s passed
testMarkDuplicatesSparkDeletingDuplicateReads[0]([Ljava.io.File;@43a3fcaa, 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.356s passed
testMarkDuplicatesSparkDeletingDuplicateReads[1]([Ljava.io.File;@2865200e, 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.407s passed
testMarkDuplicatesSparkDeletingDuplicateReads[2]([Ljava.io.File;@7864fc8, 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.348s passed
testMarkDuplicatesSparkDeletingDuplicateReads[3]([Ljava.io.File;@1781309b, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.324s passed
testMarkDuplicatesSparkDeletingDuplicateReads[4]([Ljava.io.File;@20580e37, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.327s passed
testMarkDuplicatesSparkDeletingDuplicateReads[5]([Ljava.io.File;@4a87a8cd, 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
testMarkDuplicatesSparkDeletingDuplicateReads[6]([Ljava.io.File;@1cacd8e2, 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.245s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[0]([Ljava.io.File;@1ece4d62, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]}) 0.336s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[1]([Ljava.io.File;@b6eb837, 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.344s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[2]([Ljava.io.File;@40604896, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.393s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[3]([Ljava.io.File;@64eaea74, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.344s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[4]([Ljava.io.File;@4c7953d4, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.317s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[5]([Ljava.io.File;@2209de86, 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;@14516425, 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.145s passed
testMarkDuplicatesSparkIntegrationTestLocal[0]([Ljava.io.File;@5dd0f758, 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.329s passed
testMarkDuplicatesSparkIntegrationTestLocal[1]([Ljava.io.File;@3c77d23b, 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[2]([Ljava.io.File;@66f379c2, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.354s passed
testMarkDuplicatesSparkIntegrationTestLocal[3]([Ljava.io.File;@749189d7, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.310s passed
testMarkDuplicatesSparkIntegrationTestLocal[4]([Ljava.io.File;@45e79290, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.340s passed
testMarkDuplicatesSparkIntegrationTestLocal[5]([Ljava.io.File;@716d0bc7, 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.166s passed
testMarkDuplicatesSparkIntegrationTestLocal[6]([Ljava.io.File;@7bc5803b, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 1.169s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[0]([Ljava.io.File;@1463b9af, 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.353s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[1]([Ljava.io.File;@799eb05d, 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.340s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[2]([Ljava.io.File;@39e5683d, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.337s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[3]([Ljava.io.File;@545b010b, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.327s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[4]([Ljava.io.File;@202c763b, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.303s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[5]([Ljava.io.File;@53213b52, 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.142s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[6]([Ljava.io.File;@223ef718, 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.159s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[0]([Ljava.io.File;@157e163a, 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
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[1]([Ljava.io.File;@78f86e3c, 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.353s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[2]([Ljava.io.File;@3c6664bb, 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.341s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[3]([Ljava.io.File;@340e0f81, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.305s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[4]([Ljava.io.File;@14b18cfa, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.302s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[5]([Ljava.io.File;@7bed7a94, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 1.127s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[6]([Ljava.io.File;@4c160d9, 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.100s passed
testMatePairFirstUnmapped 0.295s passed
testMatePairSecondUnmapped 0.285s passed
testNoReadGroupInRead 0.239s passed
testNonExistantReadGroupInRead 0.230s passed
testNullOpticalDuplicates 0.310s passed
testOpticalDuplicateClusterOneEndSamePositionOneCluster 0.328s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicatesWithinPixelDistance 0.286s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.304s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.298s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.295s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.297s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.298s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.290s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.300s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.288s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.313s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.303s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.298s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.302s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.296s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.289s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.301s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.295s passed
testOpticalDuplicateClusterSamePositionOneOpticalDuplicatesWithinPixelDistance 0.286s passed
testOpticalDuplicateClustersAddingSecondEndFirstSameCoordinate 0.297s passed
testOpticalDuplicateFinding 0.286s passed
testOpticalDuplicateFindingPxelDistance 0.292s passed
testOpticalDuplicatesAndPCRDuplicatesOrientationDifference 0.286s passed
testOpticalDuplicatesDifferentReadGroups 0.297s passed
testOpticalDuplicatesTheSameReadGroup 0.286s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.288s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.286s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.299s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.292s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.286s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.308s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.306s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.306s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.289s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.287s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.298s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.289s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.287s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.286s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.305s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.292s passed
testPathologicalOrderingAtTheSamePosition 0.285s passed
testReadSameStartPositionOrientationOverride 0.306s passed
testReadsHaveSameStartPositionButDifferentChromosomeNonEquivalence 0.291s passed
testSecondEndIsBeforeFirstInCoordinate 0.293s passed
testSingleMappedFragment 0.288s passed
testSingleMappedFragmentAndSingleMappedPair 0.312s passed
testSingleMappedFragmentAndTwoMappedPairs 0.291s passed
testSingleMappedPair 0.289s passed
testSingleUnmappedFragment 0.296s passed
testSingleUnmappedPair 0.290s passed
testStackOverFlowPairSetSwap 0.290s passed
testSupplementaryReadUnmappedMate 0.293s passed
testThreeGroupsOnDifferentChromosomesOfThreeMappedPairs 0.288s passed
testThreeMappedPairs 0.288s passed
testThreeMappedPairsWithMatchingSecondMate 0.286s passed
testTwoGroupsOnDifferentChromosomesOfThreeMappedPairs 0.300s passed
testTwoGroupsOnDifferentChromosomesOfTwoFragments 0.298s passed
testTwoGroupsOnDifferentChromosomesOfTwoMappedPairs 0.293s passed
testTwoMappedFragments 0.325s passed
testTwoMappedPairWithSamePosition 0.292s passed
testTwoMappedPairWithSamePositionDifferentStrands 0.286s passed
testTwoMappedPairWithSamePositionDifferentStrands2 0.294s passed
testTwoMappedPairs 0.288s passed
testTwoMappedPairsAndMappedSecondaryFragment 0.286s passed
testTwoMappedPairsAndTerminalUnmappedFragment 0.284s passed
testTwoMappedPairsAndTerminalUnmappedPair 0.300s passed
testTwoMappedPairsMatesSoftClipped 0.288s passed
testTwoMappedPairsWithOppositeOrientations 0.284s passed
testTwoMappedPairsWithOppositeOrientationsNumberTwo 0.293s passed
testTwoMappedPairsWithSoftClipping 0.285s passed
testTwoMappedPairsWithSoftClippingBoth 0.285s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnly 0.302s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnlyNoMateCigar 0.303s passed
testTwoMappedPairsWithSupplementaryReads[0](true, true, true) 0.286s passed
testTwoMappedPairsWithSupplementaryReads[1](true, false, true) 0.300s passed
testTwoMappedPairsWithSupplementaryReads[2](false, true, true) 0.286s passed
testTwoMappedPairsWithSupplementaryReads[3](true, true, false) 0.283s passed
testTwoMappedPairsWithSupplementaryReads[4](true, false, false) 0.287s passed
testTwoMappedPairsWithSupplementaryReads[5](false, true, false) 0.295s passed
testTwoUnmappedFragments 0.280s passed

Standard error

[May 19, 2025 at 7:13:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
19:13:55.419 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:13:55.420 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v0192957-SNAPSHOT
19:13:55.420 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
19:13:55.420 INFO  MarkDuplicatesSpark - Executing as root@39b899212c20 on Linux v6.11.0-1014-azure amd64
19:13:55.420 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
19:13:55.420 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 7:13:55 PM GMT
19:13:55.420 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:13:55.420 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:13:55.420 INFO  MarkDuplicatesSpark - HTSJDK Version: 4.2.0-7-gb6a1842-SNAPSHOT
19:13:55.420 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
19:13:55.420 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
19:13:55.420 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
19:13:55.420 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
19:13:55.420 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
19:13:55.420 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
19:13:55.420 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
19:13:55.421 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
19:13:55.421 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
19:13:55.421 INFO  MarkDuplicatesSpark - Requester pays: disabled
19:13:55.421 INFO  MarkDuplicatesSpark - Initializing engine
19:13:55.421 INFO  MarkDuplicatesSpark - Done initializing engine
19:13:55.421 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
19:13:55.423 INFO  MemoryStore - Block broadcast_1337 stored as values in memory (estimated size 305.5 KiB, free 1903.3 MiB)
19:13:55.430 INFO  MemoryStore - Block broadcast_1337_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1903.2 MiB)
19:13:55.430 INFO  BlockManagerInfo - Added broadcast_1337_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1918.9 MiB)
19:13:55.430 INFO  SparkContext - Created broadcast 1337 from newAPIHadoopFile at PathSplitSource.java:96
19:13:55.450 INFO  MemoryStore - Block broadcast_1338 stored as values in memory (estimated size 305.5 KiB, free 1902.9 MiB)
19:13:55.457 INFO  MemoryStore - Block broadcast_1338_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1902.9 MiB)
19:13:55.457 INFO  BlockManagerInfo - Added broadcast_1338_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1918.9 MiB)
19:13:55.457 INFO  SparkContext - Created broadcast 1338 from newAPIHadoopFile at PathSplitSource.java:96
19:13:55.489 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
19:13:55.490 INFO  FileInputFormat - Total input files to process : 1
19:13:55.490 INFO  DAGScheduler - Registering RDD 3396 (mapToPair at SparkUtils.java:161) as input to shuffle 97
19:13:55.491 INFO  DAGScheduler - Got job 413 (collect at SparkUtils.java:205) with 1 output partitions
19:13:55.491 INFO  DAGScheduler - Final stage: ResultStage 721 (collect at SparkUtils.java:205)
19:13:55.491 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 720)
19:13:55.491 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 720)
19:13:55.491 INFO  DAGScheduler - Submitting ShuffleMapStage 720 (MapPartitionsRDD[3396] at mapToPair at SparkUtils.java:161), which has no missing parents
19:13:55.508 INFO  MemoryStore - Block broadcast_1339 stored as values in memory (estimated size 459.2 KiB, free 1902.4 MiB)
19:13:55.510 INFO  MemoryStore - Block broadcast_1339_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1902.2 MiB)
19:13:55.510 INFO  BlockManagerInfo - Added broadcast_1339_piece0 in memory on localhost:36441 (size: 201.4 KiB, free: 1918.7 MiB)
19:13:55.511 INFO  SparkContext - Created broadcast 1339 from broadcast at DAGScheduler.scala:1580
19:13:55.511 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 720 (MapPartitionsRDD[3396] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:13:55.511 INFO  TaskSchedulerImpl - Adding task set 720.0 with 1 tasks resource profile 0
19:13:55.512 INFO  TaskSetManager - Starting task 0.0 in stage 720.0 (TID 650) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9650 bytes) 
19:13:55.513 INFO  Executor - Running task 0.0 in stage 720.0 (TID 650)
19:13:55.541 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam:0+1507
19:13:55.545 INFO  Executor - Finished task 0.0 in stage 720.0 (TID 650). 1148 bytes result sent to driver
19:13:55.546 INFO  TaskSetManager - Finished task 0.0 in stage 720.0 (TID 650) in 33 ms on localhost (executor driver) (1/1)
19:13:55.546 INFO  TaskSchedulerImpl - Removed TaskSet 720.0, whose tasks have all completed, from pool 
19:13:55.546 INFO  DAGScheduler - ShuffleMapStage 720 (mapToPair at SparkUtils.java:161) finished in 0.055 s
19:13:55.546 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.546 INFO  DAGScheduler - running: HashSet()
19:13:55.546 INFO  DAGScheduler - waiting: HashSet(ResultStage 721)
19:13:55.546 INFO  DAGScheduler - failed: HashSet()
19:13:55.546 INFO  DAGScheduler - Submitting ResultStage 721 (MapPartitionsRDD[3399] at mapPartitions at SparkUtils.java:188), which has no missing parents
19:13:55.547 INFO  MemoryStore - Block broadcast_1340 stored as values in memory (estimated size 7.4 KiB, free 1902.2 MiB)
19:13:55.547 INFO  MemoryStore - Block broadcast_1340_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1902.2 MiB)
19:13:55.548 INFO  BlockManagerInfo - Added broadcast_1340_piece0 in memory on localhost:36441 (size: 4.1 KiB, free: 1918.7 MiB)
19:13:55.548 INFO  SparkContext - Created broadcast 1340 from broadcast at DAGScheduler.scala:1580
19:13:55.548 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 721 (MapPartitionsRDD[3399] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
19:13:55.548 INFO  TaskSchedulerImpl - Adding task set 721.0 with 1 tasks resource profile 0
19:13:55.549 INFO  TaskSetManager - Starting task 0.0 in stage 721.0 (TID 651) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:13:55.549 INFO  Executor - Running task 0.0 in stage 721.0 (TID 651)
19:13:55.551 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
19:13:55.551 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.554 INFO  Executor - Finished task 0.0 in stage 721.0 (TID 651). 2238 bytes result sent to driver
19:13:55.554 INFO  TaskSetManager - Finished task 0.0 in stage 721.0 (TID 651) in 5 ms on localhost (executor driver) (1/1)
19:13:55.554 INFO  DAGScheduler - ResultStage 721 (collect at SparkUtils.java:205) finished in 0.007 s
19:13:55.554 INFO  DAGScheduler - Job 413 is finished. Cancelling potential speculative or zombie tasks for this job
19:13:55.554 INFO  TaskSchedulerImpl - Removed TaskSet 721.0, whose tasks have all completed, from pool 
19:13:55.555 INFO  TaskSchedulerImpl - Killing all running tasks in stage 721: Stage finished
19:13:55.555 INFO  DAGScheduler - Job 413 finished: collect at SparkUtils.java:205, took 0.065631 s
19:13:55.561 INFO  MemoryStore - Block broadcast_1341 stored as values in memory (estimated size 1632.0 B, free 1902.2 MiB)
19:13:55.561 INFO  MemoryStore - Block broadcast_1341_piece0 stored as bytes in memory (estimated size 145.0 B, free 1902.2 MiB)
19:13:55.561 INFO  BlockManagerInfo - Added broadcast_1341_piece0 in memory on localhost:36441 (size: 145.0 B, free: 1918.7 MiB)
19:13:55.561 INFO  SparkContext - Created broadcast 1341 from broadcast at MarkDuplicatesSparkUtils.java:126
19:13:55.562 INFO  MemoryStore - Block broadcast_1342 stored as values in memory (estimated size 304.0 B, free 1902.2 MiB)
19:13:55.562 INFO  MemoryStore - Block broadcast_1342_piece0 stored as bytes in memory (estimated size 37.0 B, free 1902.2 MiB)
19:13:55.562 INFO  BlockManagerInfo - Added broadcast_1342_piece0 in memory on localhost:36441 (size: 37.0 B, free: 1918.7 MiB)
19:13:55.562 INFO  SparkContext - Created broadcast 1342 from broadcast at MarkDuplicatesSparkUtils.java:127
19:13:55.574 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
19:13:55.575 INFO  DAGScheduler - Registering RDD 3408 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 100
19:13:55.575 INFO  DAGScheduler - Registering RDD 3412 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 99
19:13:55.575 INFO  DAGScheduler - Registering RDD 3416 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 98
19:13:55.575 INFO  DAGScheduler - Got job 414 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
19:13:55.575 INFO  DAGScheduler - Final stage: ResultStage 726 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
19:13:55.575 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 725)
19:13:55.575 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 725)
19:13:55.576 INFO  DAGScheduler - Submitting ShuffleMapStage 723 (MapPartitionsRDD[3408] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
19:13:55.576 INFO  MemoryStore - Block broadcast_1343 stored as values in memory (estimated size 24.2 KiB, free 1902.2 MiB)
19:13:55.577 INFO  MemoryStore - Block broadcast_1343_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1902.2 MiB)
19:13:55.577 INFO  BlockManagerInfo - Added broadcast_1343_piece0 in memory on localhost:36441 (size: 12.6 KiB, free: 1918.6 MiB)
19:13:55.577 INFO  SparkContext - Created broadcast 1343 from broadcast at DAGScheduler.scala:1580
19:13:55.578 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 723 (MapPartitionsRDD[3408] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
19:13:55.578 INFO  TaskSchedulerImpl - Adding task set 723.0 with 1 tasks resource profile 0
19:13:55.579 INFO  TaskSetManager - Starting task 0.0 in stage 723.0 (TID 652) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
19:13:55.579 INFO  Executor - Running task 0.0 in stage 723.0 (TID 652)
19:13:55.580 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
19:13:55.581 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.583 INFO  Executor - Finished task 0.0 in stage 723.0 (TID 652). 1922 bytes result sent to driver
19:13:55.584 INFO  TaskSetManager - Finished task 0.0 in stage 723.0 (TID 652) in 6 ms on localhost (executor driver) (1/1)
19:13:55.584 INFO  TaskSchedulerImpl - Removed TaskSet 723.0, whose tasks have all completed, from pool 
19:13:55.584 INFO  DAGScheduler - ShuffleMapStage 723 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
19:13:55.584 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.584 INFO  DAGScheduler - running: HashSet()
19:13:55.584 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 724, ShuffleMapStage 725, ResultStage 726)
19:13:55.584 INFO  DAGScheduler - failed: HashSet()
19:13:55.584 INFO  DAGScheduler - Submitting ShuffleMapStage 724 (MapPartitionsRDD[3412] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
19:13:55.585 INFO  MemoryStore - Block broadcast_1344 stored as values in memory (estimated size 28.3 KiB, free 1902.1 MiB)
19:13:55.586 INFO  MemoryStore - Block broadcast_1344_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1902.1 MiB)
19:13:55.586 INFO  BlockManagerInfo - Added broadcast_1344_piece0 in memory on localhost:36441 (size: 14.8 KiB, free: 1918.6 MiB)
19:13:55.586 INFO  SparkContext - Created broadcast 1344 from broadcast at DAGScheduler.scala:1580
19:13:55.586 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 724 (MapPartitionsRDD[3412] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
19:13:55.586 INFO  TaskSchedulerImpl - Adding task set 724.0 with 1 tasks resource profile 0
19:13:55.587 INFO  TaskSetManager - Starting task 0.0 in stage 724.0 (TID 653) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
19:13:55.587 INFO  Executor - Running task 0.0 in stage 724.0 (TID 653)
19:13:55.589 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
19:13:55.589 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.593 INFO  Executor - Finished task 0.0 in stage 724.0 (TID 653). 1922 bytes result sent to driver
19:13:55.594 INFO  TaskSetManager - Finished task 0.0 in stage 724.0 (TID 653) in 7 ms on localhost (executor driver) (1/1)
19:13:55.594 INFO  TaskSchedulerImpl - Removed TaskSet 724.0, whose tasks have all completed, from pool 
19:13:55.594 INFO  DAGScheduler - ShuffleMapStage 724 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
19:13:55.594 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.594 INFO  DAGScheduler - running: HashSet()
19:13:55.594 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 725, ResultStage 726)
19:13:55.594 INFO  DAGScheduler - failed: HashSet()
19:13:55.594 INFO  DAGScheduler - Submitting ShuffleMapStage 725 (MapPartitionsRDD[3416] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
19:13:55.595 INFO  MemoryStore - Block broadcast_1345 stored as values in memory (estimated size 19.0 KiB, free 1902.1 MiB)
19:13:55.595 INFO  MemoryStore - Block broadcast_1345_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1902.1 MiB)
19:13:55.595 INFO  BlockManagerInfo - Added broadcast_1345_piece0 in memory on localhost:36441 (size: 9.7 KiB, free: 1918.6 MiB)
19:13:55.596 INFO  SparkContext - Created broadcast 1345 from broadcast at DAGScheduler.scala:1580
19:13:55.596 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 725 (MapPartitionsRDD[3416] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
19:13:55.596 INFO  TaskSchedulerImpl - Adding task set 725.0 with 1 tasks resource profile 0
19:13:55.596 INFO  TaskSetManager - Starting task 0.0 in stage 725.0 (TID 654) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:13:55.597 INFO  Executor - Running task 0.0 in stage 725.0 (TID 654)
19:13:55.598 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
19:13:55.598 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.600 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
19:13:55.600 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.601 INFO  Executor - Finished task 0.0 in stage 725.0 (TID 654). 1922 bytes result sent to driver
19:13:55.601 INFO  TaskSetManager - Finished task 0.0 in stage 725.0 (TID 654) in 5 ms on localhost (executor driver) (1/1)
19:13:55.601 INFO  TaskSchedulerImpl - Removed TaskSet 725.0, whose tasks have all completed, from pool 
19:13:55.602 INFO  DAGScheduler - ShuffleMapStage 725 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.007 s
19:13:55.602 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.602 INFO  DAGScheduler - running: HashSet()
19:13:55.602 INFO  DAGScheduler - waiting: HashSet(ResultStage 726)
19:13:55.602 INFO  DAGScheduler - failed: HashSet()
19:13:55.602 INFO  DAGScheduler - Submitting ResultStage 726 (MapPartitionsRDD[3418] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
19:13:55.603 INFO  MemoryStore - Block broadcast_1346 stored as values in memory (estimated size 20.2 KiB, free 1902.1 MiB)
19:13:55.603 INFO  MemoryStore - Block broadcast_1346_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1902.1 MiB)
19:13:55.603 INFO  BlockManagerInfo - Added broadcast_1346_piece0 in memory on localhost:36441 (size: 10.6 KiB, free: 1918.6 MiB)
19:13:55.603 INFO  SparkContext - Created broadcast 1346 from broadcast at DAGScheduler.scala:1580
19:13:55.604 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 726 (MapPartitionsRDD[3418] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
19:13:55.604 INFO  TaskSchedulerImpl - Adding task set 726.0 with 1 tasks resource profile 0
19:13:55.604 INFO  TaskSetManager - Starting task 0.0 in stage 726.0 (TID 655) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:13:55.604 INFO  Executor - Running task 0.0 in stage 726.0 (TID 655)
19:13:55.606 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
19:13:55.606 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.608 INFO  Executor - Finished task 0.0 in stage 726.0 (TID 655). 1944 bytes result sent to driver
19:13:55.608 INFO  TaskSetManager - Finished task 0.0 in stage 726.0 (TID 655) in 4 ms on localhost (executor driver) (1/1)
19:13:55.609 INFO  TaskSchedulerImpl - Removed TaskSet 726.0, whose tasks have all completed, from pool 
19:13:55.609 INFO  DAGScheduler - ResultStage 726 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.007 s
19:13:55.609 INFO  DAGScheduler - Job 414 is finished. Cancelling potential speculative or zombie tasks for this job
19:13:55.609 INFO  TaskSchedulerImpl - Killing all running tasks in stage 726: Stage finished
19:13:55.609 INFO  DAGScheduler - Job 414 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.034541 s
19:13:55.619 INFO  MemoryStore - Block broadcast_1347 stored as values in memory (estimated size 20.3 KiB, free 1902.0 MiB)
19:13:55.619 INFO  MemoryStore - Block broadcast_1347_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1902.0 MiB)
19:13:55.619 INFO  BlockManagerInfo - Added broadcast_1347_piece0 in memory on localhost:36441 (size: 1850.0 B, free: 1918.6 MiB)
19:13:55.620 INFO  SparkContext - Created broadcast 1347 from broadcast at ReadsSparkSink.java:133
19:13:55.620 INFO  MemoryStore - Block broadcast_1348 stored as values in memory (estimated size 20.4 KiB, free 1902.0 MiB)
19:13:55.621 INFO  MemoryStore - Block broadcast_1348_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1902.0 MiB)
19:13:55.621 INFO  BlockManagerInfo - Added broadcast_1348_piece0 in memory on localhost:36441 (size: 1850.0 B, free: 1918.6 MiB)
19:13:55.621 INFO  SparkContext - Created broadcast 1348 from broadcast at BamSink.java:76
19:13:55.623 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
19:13:55.623 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:13:55.623 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:13:55.634 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
19:13:55.635 INFO  DAGScheduler - Registering RDD 3420 (mapToPair at SparkUtils.java:161) as input to shuffle 101
19:13:55.635 INFO  DAGScheduler - Got job 415 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
19:13:55.635 INFO  DAGScheduler - Final stage: ResultStage 731 (runJob at SparkHadoopWriter.scala:83)
19:13:55.635 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 730)
19:13:55.635 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 730)
19:13:55.635 INFO  DAGScheduler - Submitting ShuffleMapStage 730 (MapPartitionsRDD[3420] at mapToPair at SparkUtils.java:161), which has no missing parents
19:13:55.636 INFO  MemoryStore - Block broadcast_1349 stored as values in memory (estimated size 18.1 KiB, free 1902.0 MiB)
19:13:55.637 INFO  MemoryStore - Block broadcast_1349_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1902.0 MiB)
19:13:55.637 INFO  BlockManagerInfo - Added broadcast_1349_piece0 in memory on localhost:36441 (size: 9.5 KiB, free: 1918.6 MiB)
19:13:55.637 INFO  SparkContext - Created broadcast 1349 from broadcast at DAGScheduler.scala:1580
19:13:55.637 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 730 (MapPartitionsRDD[3420] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:13:55.638 INFO  TaskSchedulerImpl - Adding task set 730.0 with 1 tasks resource profile 0
19:13:55.638 INFO  TaskSetManager - Starting task 0.0 in stage 730.0 (TID 656) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:13:55.638 INFO  Executor - Running task 0.0 in stage 730.0 (TID 656)
19:13:55.640 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
19:13:55.640 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.642 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
19:13:55.642 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.644 INFO  Executor - Finished task 0.0 in stage 730.0 (TID 656). 1922 bytes result sent to driver
19:13:55.644 INFO  TaskSetManager - Finished task 0.0 in stage 730.0 (TID 656) in 6 ms on localhost (executor driver) (1/1)
19:13:55.644 INFO  TaskSchedulerImpl - Removed TaskSet 730.0, whose tasks have all completed, from pool 
19:13:55.645 INFO  DAGScheduler - ShuffleMapStage 730 (mapToPair at SparkUtils.java:161) finished in 0.008 s
19:13:55.645 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.645 INFO  DAGScheduler - running: HashSet()
19:13:55.645 INFO  DAGScheduler - waiting: HashSet(ResultStage 731)
19:13:55.645 INFO  DAGScheduler - failed: HashSet()
19:13:55.645 INFO  DAGScheduler - Submitting ResultStage 731 (MapPartitionsRDD[3425] at mapToPair at BamSink.java:91), which has no missing parents
19:13:55.652 INFO  MemoryStore - Block broadcast_1350 stored as values in memory (estimated size 163.3 KiB, free 1901.8 MiB)
19:13:55.653 INFO  MemoryStore - Block broadcast_1350_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1901.8 MiB)
19:13:55.653 INFO  BlockManagerInfo - Added broadcast_1350_piece0 in memory on localhost:36441 (size: 73.4 KiB, free: 1918.5 MiB)
19:13:55.654 INFO  SparkContext - Created broadcast 1350 from broadcast at DAGScheduler.scala:1580
19:13:55.654 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 731 (MapPartitionsRDD[3425] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
19:13:55.654 INFO  TaskSchedulerImpl - Adding task set 731.0 with 1 tasks resource profile 0
19:13:55.654 INFO  TaskSetManager - Starting task 0.0 in stage 731.0 (TID 657) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:13:55.654 INFO  Executor - Running task 0.0 in stage 731.0 (TID 657)
19:13:55.658 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
19:13:55.658 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.660 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
19:13:55.660 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:13:55.660 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:13:55.660 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
19:13:55.660 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:13:55.660 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:13:55.671 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191913557193630740740518485_3425_r_000000_0' to file:/tmp/local117265562924025115123/markdups14610737525708848971.bam.parts/_temporary/0/task_202505191913557193630740740518485_3425_r_000000
19:13:55.671 INFO  SparkHadoopMapRedUtil - attempt_202505191913557193630740740518485_3425_r_000000_0: Committed. Elapsed time: 0 ms.
19:13:55.671 INFO  Executor - Finished task 0.0 in stage 731.0 (TID 657). 1858 bytes result sent to driver
19:13:55.672 INFO  TaskSetManager - Finished task 0.0 in stage 731.0 (TID 657) in 18 ms on localhost (executor driver) (1/1)
19:13:55.672 INFO  TaskSchedulerImpl - Removed TaskSet 731.0, whose tasks have all completed, from pool 
19:13:55.672 INFO  DAGScheduler - ResultStage 731 (runJob at SparkHadoopWriter.scala:83) finished in 0.027 s
19:13:55.672 INFO  DAGScheduler - Job 415 is finished. Cancelling potential speculative or zombie tasks for this job
19:13:55.672 INFO  TaskSchedulerImpl - Killing all running tasks in stage 731: Stage finished
19:13:55.672 INFO  DAGScheduler - Job 415 finished: runJob at SparkHadoopWriter.scala:83, took 0.037767 s
19:13:55.672 INFO  SparkHadoopWriter - Start to commit write Job job_202505191913557193630740740518485_3425.
19:13:55.676 INFO  SparkHadoopWriter - Write Job job_202505191913557193630740740518485_3425 committed. Elapsed time: 3 ms.
19:13:55.683 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local117265562924025115123/markdups14610737525708848971.bam
19:13:55.685 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local117265562924025115123/markdups14610737525708848971.bam done
19:13:55.685 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local117265562924025115123/markdups14610737525708848971.bam.parts/ to /tmp/local117265562924025115123/markdups14610737525708848971.bam.sbi
19:13:55.688 INFO  IndexFileMerger - Done merging .sbi files
19:13:55.688 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local117265562924025115123/markdups14610737525708848971.bam.parts/ to /tmp/local117265562924025115123/markdups14610737525708848971.bam.bai
19:13:55.691 INFO  IndexFileMerger - Done merging .bai files
19:13:55.691 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 7:13:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
19:13:55.707 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:13:55.707 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v0192957-SNAPSHOT
19:13:55.707 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
19:13:55.707 INFO  MarkDuplicatesSpark - Executing as root@39b899212c20 on Linux v6.11.0-1014-azure amd64
19:13:55.707 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
19:13:55.707 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 7:13:55 PM GMT
19:13:55.707 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:13:55.707 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:13:55.707 INFO  MarkDuplicatesSpark - HTSJDK Version: 4.2.0-7-gb6a1842-SNAPSHOT
19:13:55.707 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
19:13:55.707 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
19:13:55.707 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
19:13:55.707 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
19:13:55.707 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
19:13:55.707 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
19:13:55.708 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
19:13:55.708 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
19:13:55.708 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
19:13:55.708 INFO  MarkDuplicatesSpark - Requester pays: disabled
19:13:55.708 INFO  MarkDuplicatesSpark - Initializing engine
19:13:55.708 INFO  MarkDuplicatesSpark - Done initializing engine
19:13:55.708 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
19:13:55.710 INFO  MemoryStore - Block broadcast_1351 stored as values in memory (estimated size 305.5 KiB, free 1901.5 MiB)
19:13:55.716 INFO  MemoryStore - Block broadcast_1351_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1901.4 MiB)
19:13:55.716 INFO  BlockManagerInfo - Added broadcast_1351_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1918.5 MiB)
19:13:55.716 INFO  SparkContext - Created broadcast 1351 from newAPIHadoopFile at PathSplitSource.java:96
19:13:55.736 INFO  MemoryStore - Block broadcast_1352 stored as values in memory (estimated size 305.5 KiB, free 1901.1 MiB)
19:13:55.742 INFO  MemoryStore - Block broadcast_1352_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1901.0 MiB)
19:13:55.743 INFO  BlockManagerInfo - Added broadcast_1352_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1918.4 MiB)
19:13:55.743 INFO  SparkContext - Created broadcast 1352 from newAPIHadoopFile at PathSplitSource.java:96
19:13:55.774 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
19:13:55.774 INFO  FileInputFormat - Total input files to process : 1
19:13:55.775 INFO  DAGScheduler - Registering RDD 3439 (mapToPair at SparkUtils.java:161) as input to shuffle 102
19:13:55.775 INFO  DAGScheduler - Got job 416 (collect at SparkUtils.java:205) with 1 output partitions
19:13:55.775 INFO  DAGScheduler - Final stage: ResultStage 733 (collect at SparkUtils.java:205)
19:13:55.775 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 732)
19:13:55.775 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 732)
19:13:55.775 INFO  DAGScheduler - Submitting ShuffleMapStage 732 (MapPartitionsRDD[3439] at mapToPair at SparkUtils.java:161), which has no missing parents
19:13:55.795 INFO  MemoryStore - Block broadcast_1353 stored as values in memory (estimated size 459.2 KiB, free 1900.6 MiB)
19:13:55.797 INFO  MemoryStore - Block broadcast_1353_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1900.4 MiB)
19:13:55.797 INFO  BlockManagerInfo - Added broadcast_1353_piece0 in memory on localhost:36441 (size: 201.4 KiB, free: 1918.2 MiB)
19:13:55.797 INFO  SparkContext - Created broadcast 1353 from broadcast at DAGScheduler.scala:1580
19:13:55.797 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 732 (MapPartitionsRDD[3439] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:13:55.797 INFO  TaskSchedulerImpl - Adding task set 732.0 with 1 tasks resource profile 0
19:13:55.798 INFO  TaskSetManager - Starting task 0.0 in stage 732.0 (TID 658) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9651 bytes) 
19:13:55.798 INFO  Executor - Running task 0.0 in stage 732.0 (TID 658)
19:13:55.826 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam:0+1856
19:13:55.830 INFO  Executor - Finished task 0.0 in stage 732.0 (TID 658). 1148 bytes result sent to driver
19:13:55.831 INFO  TaskSetManager - Finished task 0.0 in stage 732.0 (TID 658) in 33 ms on localhost (executor driver) (1/1)
19:13:55.831 INFO  TaskSchedulerImpl - Removed TaskSet 732.0, whose tasks have all completed, from pool 
19:13:55.831 INFO  DAGScheduler - ShuffleMapStage 732 (mapToPair at SparkUtils.java:161) finished in 0.055 s
19:13:55.831 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.831 INFO  DAGScheduler - running: HashSet()
19:13:55.831 INFO  DAGScheduler - waiting: HashSet(ResultStage 733)
19:13:55.831 INFO  DAGScheduler - failed: HashSet()
19:13:55.831 INFO  DAGScheduler - Submitting ResultStage 733 (MapPartitionsRDD[3442] at mapPartitions at SparkUtils.java:188), which has no missing parents
19:13:55.832 INFO  MemoryStore - Block broadcast_1354 stored as values in memory (estimated size 7.4 KiB, free 1900.4 MiB)
19:13:55.832 INFO  MemoryStore - Block broadcast_1354_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1900.4 MiB)
19:13:55.833 INFO  BlockManagerInfo - Added broadcast_1354_piece0 in memory on localhost:36441 (size: 4.1 KiB, free: 1918.2 MiB)
19:13:55.833 INFO  SparkContext - Created broadcast 1354 from broadcast at DAGScheduler.scala:1580
19:13:55.833 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 733 (MapPartitionsRDD[3442] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
19:13:55.833 INFO  TaskSchedulerImpl - Adding task set 733.0 with 1 tasks resource profile 0
19:13:55.833 INFO  TaskSetManager - Starting task 0.0 in stage 733.0 (TID 659) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:13:55.834 INFO  Executor - Running task 0.0 in stage 733.0 (TID 659)
19:13:55.835 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
19:13:55.835 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.837 INFO  Executor - Finished task 0.0 in stage 733.0 (TID 659). 2495 bytes result sent to driver
19:13:55.837 INFO  TaskSetManager - Finished task 0.0 in stage 733.0 (TID 659) in 4 ms on localhost (executor driver) (1/1)
19:13:55.837 INFO  TaskSchedulerImpl - Removed TaskSet 733.0, whose tasks have all completed, from pool 
19:13:55.837 INFO  DAGScheduler - ResultStage 733 (collect at SparkUtils.java:205) finished in 0.005 s
19:13:55.837 INFO  DAGScheduler - Job 416 is finished. Cancelling potential speculative or zombie tasks for this job
19:13:55.837 INFO  TaskSchedulerImpl - Killing all running tasks in stage 733: Stage finished
19:13:55.837 INFO  DAGScheduler - Job 416 finished: collect at SparkUtils.java:205, took 0.063271 s
19:13:55.841 INFO  MemoryStore - Block broadcast_1355 stored as values in memory (estimated size 1632.0 B, free 1900.4 MiB)
19:13:55.842 INFO  MemoryStore - Block broadcast_1355_piece0 stored as bytes in memory (estimated size 145.0 B, free 1900.4 MiB)
19:13:55.842 INFO  BlockManagerInfo - Added broadcast_1355_piece0 in memory on localhost:36441 (size: 145.0 B, free: 1918.2 MiB)
19:13:55.842 INFO  SparkContext - Created broadcast 1355 from broadcast at MarkDuplicatesSparkUtils.java:126
19:13:55.842 INFO  MemoryStore - Block broadcast_1356 stored as values in memory (estimated size 304.0 B, free 1900.4 MiB)
19:13:55.843 INFO  MemoryStore - Block broadcast_1356_piece0 stored as bytes in memory (estimated size 37.0 B, free 1900.4 MiB)
19:13:55.843 INFO  BlockManagerInfo - Added broadcast_1356_piece0 in memory on localhost:36441 (size: 37.0 B, free: 1918.2 MiB)
19:13:55.843 INFO  SparkContext - Created broadcast 1356 from broadcast at MarkDuplicatesSparkUtils.java:127
19:13:55.854 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
19:13:55.855 INFO  DAGScheduler - Registering RDD 3451 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 105
19:13:55.855 INFO  DAGScheduler - Registering RDD 3455 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 104
19:13:55.855 INFO  DAGScheduler - Registering RDD 3459 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 103
19:13:55.855 INFO  DAGScheduler - Got job 417 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
19:13:55.855 INFO  DAGScheduler - Final stage: ResultStage 738 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
19:13:55.855 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 737)
19:13:55.855 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 737)
19:13:55.856 INFO  DAGScheduler - Submitting ShuffleMapStage 735 (MapPartitionsRDD[3451] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
19:13:55.856 INFO  MemoryStore - Block broadcast_1357 stored as values in memory (estimated size 24.2 KiB, free 1900.4 MiB)
19:13:55.857 INFO  MemoryStore - Block broadcast_1357_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1900.3 MiB)
19:13:55.857 INFO  BlockManagerInfo - Added broadcast_1357_piece0 in memory on localhost:36441 (size: 12.6 KiB, free: 1918.2 MiB)
19:13:55.857 INFO  SparkContext - Created broadcast 1357 from broadcast at DAGScheduler.scala:1580
19:13:55.857 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 735 (MapPartitionsRDD[3451] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
19:13:55.857 INFO  TaskSchedulerImpl - Adding task set 735.0 with 1 tasks resource profile 0
19:13:55.858 INFO  TaskSetManager - Starting task 0.0 in stage 735.0 (TID 660) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
19:13:55.858 INFO  Executor - Running task 0.0 in stage 735.0 (TID 660)
19:13:55.860 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
19:13:55.860 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.864 INFO  Executor - Finished task 0.0 in stage 735.0 (TID 660). 1922 bytes result sent to driver
19:13:55.864 INFO  TaskSetManager - Finished task 0.0 in stage 735.0 (TID 660) in 6 ms on localhost (executor driver) (1/1)
19:13:55.864 INFO  TaskSchedulerImpl - Removed TaskSet 735.0, whose tasks have all completed, from pool 
19:13:55.864 INFO  DAGScheduler - ShuffleMapStage 735 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
19:13:55.864 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.864 INFO  DAGScheduler - running: HashSet()
19:13:55.864 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 736, ShuffleMapStage 737, ResultStage 738)
19:13:55.864 INFO  DAGScheduler - failed: HashSet()
19:13:55.864 INFO  DAGScheduler - Submitting ShuffleMapStage 736 (MapPartitionsRDD[3455] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
19:13:55.865 INFO  MemoryStore - Block broadcast_1358 stored as values in memory (estimated size 28.3 KiB, free 1900.3 MiB)
19:13:55.866 INFO  MemoryStore - Block broadcast_1358_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1900.3 MiB)
19:13:55.866 INFO  BlockManagerInfo - Added broadcast_1358_piece0 in memory on localhost:36441 (size: 14.8 KiB, free: 1918.2 MiB)
19:13:55.866 INFO  SparkContext - Created broadcast 1358 from broadcast at DAGScheduler.scala:1580
19:13:55.866 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 736 (MapPartitionsRDD[3455] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
19:13:55.866 INFO  TaskSchedulerImpl - Adding task set 736.0 with 1 tasks resource profile 0
19:13:55.867 INFO  TaskSetManager - Starting task 0.0 in stage 736.0 (TID 661) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
19:13:55.867 INFO  Executor - Running task 0.0 in stage 736.0 (TID 661)
19:13:55.868 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
19:13:55.869 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.872 INFO  Executor - Finished task 0.0 in stage 736.0 (TID 661). 1922 bytes result sent to driver
19:13:55.872 INFO  TaskSetManager - Finished task 0.0 in stage 736.0 (TID 661) in 6 ms on localhost (executor driver) (1/1)
19:13:55.872 INFO  TaskSchedulerImpl - Removed TaskSet 736.0, whose tasks have all completed, from pool 
19:13:55.872 INFO  DAGScheduler - ShuffleMapStage 736 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
19:13:55.872 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.872 INFO  DAGScheduler - running: HashSet()
19:13:55.872 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 737, ResultStage 738)
19:13:55.872 INFO  DAGScheduler - failed: HashSet()
19:13:55.873 INFO  DAGScheduler - Submitting ShuffleMapStage 737 (MapPartitionsRDD[3459] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
19:13:55.873 INFO  MemoryStore - Block broadcast_1359 stored as values in memory (estimated size 19.0 KiB, free 1900.3 MiB)
19:13:55.874 INFO  MemoryStore - Block broadcast_1359_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1900.3 MiB)
19:13:55.874 INFO  BlockManagerInfo - Added broadcast_1359_piece0 in memory on localhost:36441 (size: 9.7 KiB, free: 1918.2 MiB)
19:13:55.874 INFO  SparkContext - Created broadcast 1359 from broadcast at DAGScheduler.scala:1580
19:13:55.874 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 737 (MapPartitionsRDD[3459] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
19:13:55.874 INFO  TaskSchedulerImpl - Adding task set 737.0 with 1 tasks resource profile 0
19:13:55.875 INFO  TaskSetManager - Starting task 0.0 in stage 737.0 (TID 662) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:13:55.875 INFO  Executor - Running task 0.0 in stage 737.0 (TID 662)
19:13:55.877 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
19:13:55.877 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.879 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
19:13:55.880 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.881 INFO  Executor - Finished task 0.0 in stage 737.0 (TID 662). 1922 bytes result sent to driver
19:13:55.882 INFO  TaskSetManager - Finished task 0.0 in stage 737.0 (TID 662) in 8 ms on localhost (executor driver) (1/1)
19:13:55.882 INFO  TaskSchedulerImpl - Removed TaskSet 737.0, whose tasks have all completed, from pool 
19:13:55.882 INFO  DAGScheduler - ShuffleMapStage 737 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.009 s
19:13:55.882 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.882 INFO  DAGScheduler - running: HashSet()
19:13:55.882 INFO  DAGScheduler - waiting: HashSet(ResultStage 738)
19:13:55.882 INFO  DAGScheduler - failed: HashSet()
19:13:55.882 INFO  DAGScheduler - Submitting ResultStage 738 (MapPartitionsRDD[3461] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
19:13:55.883 INFO  MemoryStore - Block broadcast_1360 stored as values in memory (estimated size 20.2 KiB, free 1900.3 MiB)
19:13:55.883 INFO  MemoryStore - Block broadcast_1360_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1900.2 MiB)
19:13:55.884 INFO  BlockManagerInfo - Added broadcast_1360_piece0 in memory on localhost:36441 (size: 10.6 KiB, free: 1918.1 MiB)
19:13:55.884 INFO  SparkContext - Created broadcast 1360 from broadcast at DAGScheduler.scala:1580
19:13:55.884 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 738 (MapPartitionsRDD[3461] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
19:13:55.884 INFO  TaskSchedulerImpl - Adding task set 738.0 with 1 tasks resource profile 0
19:13:55.884 INFO  TaskSetManager - Starting task 0.0 in stage 738.0 (TID 663) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:13:55.884 INFO  Executor - Running task 0.0 in stage 738.0 (TID 663)
19:13:55.886 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
19:13:55.886 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.888 INFO  Executor - Finished task 0.0 in stage 738.0 (TID 663). 2053 bytes result sent to driver
19:13:55.888 INFO  TaskSetManager - Finished task 0.0 in stage 738.0 (TID 663) in 4 ms on localhost (executor driver) (1/1)
19:13:55.889 INFO  TaskSchedulerImpl - Removed TaskSet 738.0, whose tasks have all completed, from pool 
19:13:55.889 INFO  DAGScheduler - ResultStage 738 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.007 s
19:13:55.889 INFO  DAGScheduler - Job 417 is finished. Cancelling potential speculative or zombie tasks for this job
19:13:55.889 INFO  TaskSchedulerImpl - Killing all running tasks in stage 738: Stage finished
19:13:55.889 INFO  DAGScheduler - Job 417 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.034493 s
19:13:55.899 INFO  MemoryStore - Block broadcast_1361 stored as values in memory (estimated size 20.3 KiB, free 1900.2 MiB)
19:13:55.899 INFO  MemoryStore - Block broadcast_1361_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.2 MiB)
19:13:55.899 INFO  BlockManagerInfo - Added broadcast_1361_piece0 in memory on localhost:36441 (size: 1850.0 B, free: 1918.1 MiB)
19:13:55.899 INFO  SparkContext - Created broadcast 1361 from broadcast at ReadsSparkSink.java:133
19:13:55.900 INFO  MemoryStore - Block broadcast_1362 stored as values in memory (estimated size 20.4 KiB, free 1900.2 MiB)
19:13:55.900 INFO  MemoryStore - Block broadcast_1362_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.2 MiB)
19:13:55.900 INFO  BlockManagerInfo - Added broadcast_1362_piece0 in memory on localhost:36441 (size: 1850.0 B, free: 1918.1 MiB)
19:13:55.901 INFO  SparkContext - Created broadcast 1362 from broadcast at BamSink.java:76
19:13:55.902 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
19:13:55.902 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:13:55.902 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:13:55.914 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
19:13:55.914 INFO  DAGScheduler - Registering RDD 3463 (mapToPair at SparkUtils.java:161) as input to shuffle 106
19:13:55.914 INFO  DAGScheduler - Got job 418 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
19:13:55.914 INFO  DAGScheduler - Final stage: ResultStage 743 (runJob at SparkHadoopWriter.scala:83)
19:13:55.914 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 742)
19:13:55.914 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 742)
19:13:55.915 INFO  DAGScheduler - Submitting ShuffleMapStage 742 (MapPartitionsRDD[3463] at mapToPair at SparkUtils.java:161), which has no missing parents
19:13:55.915 INFO  MemoryStore - Block broadcast_1363 stored as values in memory (estimated size 18.1 KiB, free 1900.2 MiB)
19:13:55.916 INFO  MemoryStore - Block broadcast_1363_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1900.2 MiB)
19:13:55.916 INFO  BlockManagerInfo - Added broadcast_1363_piece0 in memory on localhost:36441 (size: 9.5 KiB, free: 1918.1 MiB)
19:13:55.916 INFO  SparkContext - Created broadcast 1363 from broadcast at DAGScheduler.scala:1580
19:13:55.916 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 742 (MapPartitionsRDD[3463] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:13:55.916 INFO  TaskSchedulerImpl - Adding task set 742.0 with 1 tasks resource profile 0
19:13:55.917 INFO  TaskSetManager - Starting task 0.0 in stage 742.0 (TID 664) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:13:55.917 INFO  Executor - Running task 0.0 in stage 742.0 (TID 664)
19:13:55.919 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
19:13:55.919 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.921 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
19:13:55.922 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.923 INFO  Executor - Finished task 0.0 in stage 742.0 (TID 664). 1922 bytes result sent to driver
19:13:55.923 INFO  TaskSetManager - Finished task 0.0 in stage 742.0 (TID 664) in 6 ms on localhost (executor driver) (1/1)
19:13:55.923 INFO  TaskSchedulerImpl - Removed TaskSet 742.0, whose tasks have all completed, from pool 
19:13:55.924 INFO  DAGScheduler - ShuffleMapStage 742 (mapToPair at SparkUtils.java:161) finished in 0.008 s
19:13:55.924 INFO  DAGScheduler - looking for newly runnable stages
19:13:55.924 INFO  DAGScheduler - running: HashSet()
19:13:55.924 INFO  DAGScheduler - waiting: HashSet(ResultStage 743)
19:13:55.924 INFO  DAGScheduler - failed: HashSet()
19:13:55.924 INFO  DAGScheduler - Submitting ResultStage 743 (MapPartitionsRDD[3468] at mapToPair at BamSink.java:91), which has no missing parents
19:13:55.930 INFO  MemoryStore - Block broadcast_1364 stored as values in memory (estimated size 163.3 KiB, free 1900.0 MiB)
19:13:55.931 INFO  MemoryStore - Block broadcast_1364_piece0 stored as bytes in memory (estimated size 73.5 KiB, free 1899.9 MiB)
19:13:55.931 INFO  BlockManagerInfo - Added broadcast_1364_piece0 in memory on localhost:36441 (size: 73.5 KiB, free: 1918.1 MiB)
19:13:55.931 INFO  SparkContext - Created broadcast 1364 from broadcast at DAGScheduler.scala:1580
19:13:55.932 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 743 (MapPartitionsRDD[3468] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
19:13:55.932 INFO  TaskSchedulerImpl - Adding task set 743.0 with 1 tasks resource profile 0
19:13:55.932 INFO  TaskSetManager - Starting task 0.0 in stage 743.0 (TID 665) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:13:55.932 INFO  Executor - Running task 0.0 in stage 743.0 (TID 665)
19:13:55.936 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
19:13:55.936 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:13:55.938 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
19:13:55.938 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:13:55.938 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:13:55.938 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
19:13:55.938 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:13:55.938 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:13:55.949 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191913556159167273641598657_3468_r_000000_0' to file:/tmp/local117265562924025115123/markdups17618858516656755043.bam.parts/_temporary/0/task_202505191913556159167273641598657_3468_r_000000
19:13:55.949 INFO  SparkHadoopMapRedUtil - attempt_202505191913556159167273641598657_3468_r_000000_0: Committed. Elapsed time: 0 ms.
19:13:55.949 INFO  Executor - Finished task 0.0 in stage 743.0 (TID 665). 1858 bytes result sent to driver
19:13:55.950 INFO  TaskSetManager - Finished task 0.0 in stage 743.0 (TID 665) in 18 ms on localhost (executor driver) (1/1)
19:13:55.950 INFO  TaskSchedulerImpl - Removed TaskSet 743.0, whose tasks have all completed, from pool 
19:13:55.950 INFO  DAGScheduler - ResultStage 743 (runJob at SparkHadoopWriter.scala:83) finished in 0.026 s
19:13:55.950 INFO  DAGScheduler - Job 418 is finished. Cancelling potential speculative or zombie tasks for this job
19:13:55.950 INFO  TaskSchedulerImpl - Killing all running tasks in stage 743: Stage finished
19:13:55.950 INFO  DAGScheduler - Job 418 finished: runJob at SparkHadoopWriter.scala:83, took 0.036279 s
19:13:55.950 INFO  SparkHadoopWriter - Start to commit write Job job_202505191913556159167273641598657_3468.
19:13:55.954 INFO  SparkHadoopWriter - Write Job job_202505191913556159167273641598657_3468 committed. Elapsed time: 3 ms.
19:13:55.959 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local117265562924025115123/markdups17618858516656755043.bam
19:13:55.961 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local117265562924025115123/markdups17618858516656755043.bam done
19:13:55.961 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local117265562924025115123/markdups17618858516656755043.bam.parts/ to /tmp/local117265562924025115123/markdups17618858516656755043.bam.sbi
19:13:55.964 INFO  IndexFileMerger - Done merging .sbi files
19:13:55.964 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local117265562924025115123/markdups17618858516656755043.bam.parts/ to /tmp/local117265562924025115123/markdups17618858516656755043.bam.bai
19:13:55.967 INFO  IndexFileMerger - Done merging .bai files
19:13:55.967 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 7:13:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:13:59 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:00 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:00 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:03 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:04 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:04 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
19:14:19.979 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:19.979 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v0192957-SNAPSHOT
19:14:19.979 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
19:14:19.979 INFO  MarkDuplicatesSpark - Executing as root@39b899212c20 on Linux v6.11.0-1014-azure amd64
19:14:19.979 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
19:14:19.979 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 7:14:19 PM GMT
19:14:19.979 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:19.979 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:19.979 INFO  MarkDuplicatesSpark - HTSJDK Version: 4.2.0-7-gb6a1842-SNAPSHOT
19:14:19.979 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
19:14:19.979 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
19:14:19.979 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
19:14:19.979 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
19:14:19.979 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
19:14:19.979 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
19:14:19.979 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
19:14:19.979 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
19:14:19.979 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
19:14:19.979 INFO  MarkDuplicatesSpark - Requester pays: disabled
19:14:19.979 INFO  MarkDuplicatesSpark - Initializing engine
19:14:19.979 INFO  MarkDuplicatesSpark - Done initializing engine
19:14:19.979 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
19:14:19.982 INFO  MemoryStore - Block broadcast_1941 stored as values in memory (estimated size 305.5 KiB, free 1917.1 MiB)
19:14:19.988 INFO  MemoryStore - Block broadcast_1941_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1917.1 MiB)
19:14:19.988 INFO  BlockManagerInfo - Added broadcast_1941_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1919.3 MiB)
19:14:19.988 INFO  SparkContext - Created broadcast 1941 from newAPIHadoopFile at PathSplitSource.java:96
19:14:20.009 INFO  MemoryStore - Block broadcast_1942 stored as values in memory (estimated size 305.5 KiB, free 1916.8 MiB)
19:14:20.016 INFO  MemoryStore - Block broadcast_1942_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1916.7 MiB)
19:14:20.016 INFO  BlockManagerInfo - Added broadcast_1942_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1919.2 MiB)
19:14:20.016 INFO  SparkContext - Created broadcast 1942 from newAPIHadoopFile at PathSplitSource.java:96
19:14:20.048 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
19:14:20.048 INFO  FileInputFormat - Total input files to process : 1
19:14:20.048 INFO  DAGScheduler - Registering RDD 5360 (mapToPair at SparkUtils.java:161) as input to shuffle 297
19:14:20.049 INFO  DAGScheduler - Got job 549 (collect at SparkUtils.java:205) with 1 output partitions
19:14:20.049 INFO  DAGScheduler - Final stage: ResultStage 1205 (collect at SparkUtils.java:205)
19:14:20.049 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1204)
19:14:20.049 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1204)
19:14:20.049 INFO  DAGScheduler - Submitting ShuffleMapStage 1204 (MapPartitionsRDD[5360] at mapToPair at SparkUtils.java:161), which has no missing parents
19:14:20.072 INFO  MemoryStore - Block broadcast_1943 stored as values in memory (estimated size 492.6 KiB, free 1916.2 MiB)
19:14:20.074 INFO  MemoryStore - Block broadcast_1943_piece0 stored as bytes in memory (estimated size 208.9 KiB, free 1916.0 MiB)
19:14:20.074 INFO  BlockManagerInfo - Added broadcast_1943_piece0 in memory on localhost:36441 (size: 208.9 KiB, free: 1919.0 MiB)
19:14:20.074 INFO  SparkContext - Created broadcast 1943 from broadcast at DAGScheduler.scala:1580
19:14:20.075 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1204 (MapPartitionsRDD[5360] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:14:20.075 INFO  TaskSchedulerImpl - Adding task set 1204.0 with 1 tasks resource profile 0
19:14:20.075 INFO  TaskSetManager - Starting task 0.0 in stage 1204.0 (TID 1036) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9674 bytes) 
19:14:20.075 INFO  Executor - Running task 0.0 in stage 1204.0 (TID 1036)
19:14:20.111 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam:0+13412
19:14:20.116 INFO  Executor - Finished task 0.0 in stage 1204.0 (TID 1036). 1148 bytes result sent to driver
19:14:20.117 INFO  TaskSetManager - Finished task 0.0 in stage 1204.0 (TID 1036) in 41 ms on localhost (executor driver) (1/1)
19:14:20.117 INFO  TaskSchedulerImpl - Removed TaskSet 1204.0, whose tasks have all completed, from pool 
19:14:20.117 INFO  DAGScheduler - ShuffleMapStage 1204 (mapToPair at SparkUtils.java:161) finished in 0.068 s
19:14:20.117 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.117 INFO  DAGScheduler - running: HashSet()
19:14:20.117 INFO  DAGScheduler - waiting: HashSet(ResultStage 1205)
19:14:20.117 INFO  DAGScheduler - failed: HashSet()
19:14:20.117 INFO  DAGScheduler - Submitting ResultStage 1205 (MapPartitionsRDD[5363] at mapPartitions at SparkUtils.java:188), which has no missing parents
19:14:20.117 INFO  MemoryStore - Block broadcast_1944 stored as values in memory (estimated size 7.4 KiB, free 1916.0 MiB)
19:14:20.118 INFO  MemoryStore - Block broadcast_1944_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1916.0 MiB)
19:14:20.118 INFO  BlockManagerInfo - Added broadcast_1944_piece0 in memory on localhost:36441 (size: 4.1 KiB, free: 1919.0 MiB)
19:14:20.118 INFO  SparkContext - Created broadcast 1944 from broadcast at DAGScheduler.scala:1580
19:14:20.118 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1205 (MapPartitionsRDD[5363] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
19:14:20.118 INFO  TaskSchedulerImpl - Adding task set 1205.0 with 1 tasks resource profile 0
19:14:20.119 INFO  TaskSetManager - Starting task 0.0 in stage 1205.0 (TID 1037) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.119 INFO  Executor - Running task 0.0 in stage 1205.0 (TID 1037)
19:14:20.120 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
19:14:20.120 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.124 INFO  Executor - Finished task 0.0 in stage 1205.0 (TID 1037). 2329 bytes result sent to driver
19:14:20.124 INFO  TaskSetManager - Finished task 0.0 in stage 1205.0 (TID 1037) in 5 ms on localhost (executor driver) (1/1)
19:14:20.124 INFO  TaskSchedulerImpl - Removed TaskSet 1205.0, whose tasks have all completed, from pool 
19:14:20.124 INFO  DAGScheduler - ResultStage 1205 (collect at SparkUtils.java:205) finished in 0.007 s
19:14:20.124 INFO  DAGScheduler - Job 549 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.124 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1205: Stage finished
19:14:20.124 INFO  DAGScheduler - Job 549 finished: collect at SparkUtils.java:205, took 0.076610 s
19:14:20.130 INFO  MemoryStore - Block broadcast_1945 stored as values in memory (estimated size 7.8 KiB, free 1916.0 MiB)
19:14:20.130 INFO  MemoryStore - Block broadcast_1945_piece0 stored as bytes in memory (estimated size 540.0 B, free 1916.0 MiB)
19:14:20.130 INFO  BlockManagerInfo - Added broadcast_1945_piece0 in memory on localhost:36441 (size: 540.0 B, free: 1919.0 MiB)
19:14:20.130 INFO  SparkContext - Created broadcast 1945 from broadcast at MarkDuplicatesSparkUtils.java:126
19:14:20.131 INFO  MemoryStore - Block broadcast_1946 stored as values in memory (estimated size 2.6 KiB, free 1916.0 MiB)
19:14:20.131 INFO  MemoryStore - Block broadcast_1946_piece0 stored as bytes in memory (estimated size 209.0 B, free 1916.0 MiB)
19:14:20.131 INFO  BlockManagerInfo - Added broadcast_1946_piece0 in memory on localhost:36441 (size: 209.0 B, free: 1919.0 MiB)
19:14:20.131 INFO  SparkContext - Created broadcast 1946 from broadcast at MarkDuplicatesSparkUtils.java:127
19:14:20.145 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
19:14:20.145 INFO  DAGScheduler - Registering RDD 5372 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 300
19:14:20.145 INFO  DAGScheduler - Registering RDD 5376 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 299
19:14:20.145 INFO  DAGScheduler - Registering RDD 5380 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 298
19:14:20.145 INFO  DAGScheduler - Got job 550 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
19:14:20.145 INFO  DAGScheduler - Final stage: ResultStage 1210 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
19:14:20.146 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1209)
19:14:20.146 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1209)
19:14:20.146 INFO  DAGScheduler - Submitting ShuffleMapStage 1207 (MapPartitionsRDD[5372] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
19:14:20.147 INFO  MemoryStore - Block broadcast_1947 stored as values in memory (estimated size 57.6 KiB, free 1916.0 MiB)
19:14:20.147 INFO  MemoryStore - Block broadcast_1947_piece0 stored as bytes in memory (estimated size 19.8 KiB, free 1915.9 MiB)
19:14:20.147 INFO  BlockManagerInfo - Added broadcast_1947_piece0 in memory on localhost:36441 (size: 19.8 KiB, free: 1919.0 MiB)
19:14:20.147 INFO  SparkContext - Created broadcast 1947 from broadcast at DAGScheduler.scala:1580
19:14:20.148 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1207 (MapPartitionsRDD[5372] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
19:14:20.148 INFO  TaskSchedulerImpl - Adding task set 1207.0 with 1 tasks resource profile 0
19:14:20.148 INFO  TaskSetManager - Starting task 0.0 in stage 1207.0 (TID 1038) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
19:14:20.148 INFO  Executor - Running task 0.0 in stage 1207.0 (TID 1038)
19:14:20.150 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
19:14:20.150 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.154 INFO  Executor - Finished task 0.0 in stage 1207.0 (TID 1038). 1922 bytes result sent to driver
19:14:20.154 INFO  TaskSetManager - Finished task 0.0 in stage 1207.0 (TID 1038) in 6 ms on localhost (executor driver) (1/1)
19:14:20.154 INFO  TaskSchedulerImpl - Removed TaskSet 1207.0, whose tasks have all completed, from pool 
19:14:20.154 INFO  DAGScheduler - ShuffleMapStage 1207 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
19:14:20.154 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.154 INFO  DAGScheduler - running: HashSet()
19:14:20.154 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1208, ShuffleMapStage 1209, ResultStage 1210)
19:14:20.154 INFO  DAGScheduler - failed: HashSet()
19:14:20.155 INFO  DAGScheduler - Submitting ShuffleMapStage 1208 (MapPartitionsRDD[5376] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
19:14:20.156 INFO  MemoryStore - Block broadcast_1948 stored as values in memory (estimated size 61.7 KiB, free 1915.9 MiB)
19:14:20.156 INFO  MemoryStore - Block broadcast_1948_piece0 stored as bytes in memory (estimated size 22.0 KiB, free 1915.9 MiB)
19:14:20.156 INFO  BlockManagerInfo - Added broadcast_1948_piece0 in memory on localhost:36441 (size: 22.0 KiB, free: 1919.0 MiB)
19:14:20.156 INFO  SparkContext - Created broadcast 1948 from broadcast at DAGScheduler.scala:1580
19:14:20.157 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1208 (MapPartitionsRDD[5376] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
19:14:20.157 INFO  TaskSchedulerImpl - Adding task set 1208.0 with 1 tasks resource profile 0
19:14:20.157 INFO  TaskSetManager - Starting task 0.0 in stage 1208.0 (TID 1039) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
19:14:20.157 INFO  Executor - Running task 0.0 in stage 1208.0 (TID 1039)
19:14:20.159 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
19:14:20.159 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.163 INFO  Executor - Finished task 0.0 in stage 1208.0 (TID 1039). 1922 bytes result sent to driver
19:14:20.163 INFO  TaskSetManager - Finished task 0.0 in stage 1208.0 (TID 1039) in 6 ms on localhost (executor driver) (1/1)
19:14:20.163 INFO  TaskSchedulerImpl - Removed TaskSet 1208.0, whose tasks have all completed, from pool 
19:14:20.163 INFO  DAGScheduler - ShuffleMapStage 1208 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.008 s
19:14:20.163 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.163 INFO  DAGScheduler - running: HashSet()
19:14:20.163 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1209, ResultStage 1210)
19:14:20.164 INFO  DAGScheduler - failed: HashSet()
19:14:20.164 INFO  DAGScheduler - Submitting ShuffleMapStage 1209 (MapPartitionsRDD[5380] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
19:14:20.164 INFO  MemoryStore - Block broadcast_1949 stored as values in memory (estimated size 52.4 KiB, free 1915.8 MiB)
19:14:20.165 INFO  MemoryStore - Block broadcast_1949_piece0 stored as bytes in memory (estimated size 17.3 KiB, free 1915.8 MiB)
19:14:20.165 INFO  BlockManagerInfo - Added broadcast_1949_piece0 in memory on localhost:36441 (size: 17.3 KiB, free: 1919.0 MiB)
19:14:20.165 INFO  SparkContext - Created broadcast 1949 from broadcast at DAGScheduler.scala:1580
19:14:20.165 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1209 (MapPartitionsRDD[5380] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
19:14:20.165 INFO  TaskSchedulerImpl - Adding task set 1209.0 with 1 tasks resource profile 0
19:14:20.166 INFO  TaskSetManager - Starting task 0.0 in stage 1209.0 (TID 1040) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:14:20.166 INFO  Executor - Running task 0.0 in stage 1209.0 (TID 1040)
19:14:20.167 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
19:14:20.167 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.170 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
19:14:20.170 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.171 INFO  Executor - Finished task 0.0 in stage 1209.0 (TID 1040). 1922 bytes result sent to driver
19:14:20.171 INFO  TaskSetManager - Finished task 0.0 in stage 1209.0 (TID 1040) in 5 ms on localhost (executor driver) (1/1)
19:14:20.172 INFO  TaskSchedulerImpl - Removed TaskSet 1209.0, whose tasks have all completed, from pool 
19:14:20.172 INFO  DAGScheduler - ShuffleMapStage 1209 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
19:14:20.172 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.172 INFO  DAGScheduler - running: HashSet()
19:14:20.172 INFO  DAGScheduler - waiting: HashSet(ResultStage 1210)
19:14:20.172 INFO  DAGScheduler - failed: HashSet()
19:14:20.172 INFO  DAGScheduler - Submitting ResultStage 1210 (MapPartitionsRDD[5382] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
19:14:20.173 INFO  MemoryStore - Block broadcast_1950 stored as values in memory (estimated size 53.6 KiB, free 1915.7 MiB)
19:14:20.173 INFO  MemoryStore - Block broadcast_1950_piece0 stored as bytes in memory (estimated size 18.0 KiB, free 1915.7 MiB)
19:14:20.173 INFO  BlockManagerInfo - Added broadcast_1950_piece0 in memory on localhost:36441 (size: 18.0 KiB, free: 1918.9 MiB)
19:14:20.173 INFO  SparkContext - Created broadcast 1950 from broadcast at DAGScheduler.scala:1580
19:14:20.174 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1210 (MapPartitionsRDD[5382] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
19:14:20.174 INFO  TaskSchedulerImpl - Adding task set 1210.0 with 1 tasks resource profile 0
19:14:20.174 INFO  TaskSetManager - Starting task 0.0 in stage 1210.0 (TID 1041) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.174 INFO  Executor - Running task 0.0 in stage 1210.0 (TID 1041)
19:14:20.175 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
19:14:20.175 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.176 INFO  Executor - Finished task 0.0 in stage 1210.0 (TID 1041). 2371 bytes result sent to driver
19:14:20.177 INFO  TaskSetManager - Finished task 0.0 in stage 1210.0 (TID 1041) in 3 ms on localhost (executor driver) (1/1)
19:14:20.177 INFO  TaskSchedulerImpl - Removed TaskSet 1210.0, whose tasks have all completed, from pool 
19:14:20.177 INFO  DAGScheduler - ResultStage 1210 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
19:14:20.177 INFO  DAGScheduler - Job 550 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.177 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1210: Stage finished
19:14:20.177 INFO  DAGScheduler - Job 550 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.032207 s
19:14:20.188 INFO  MemoryStore - Block broadcast_1951 stored as values in memory (estimated size 179.4 KiB, free 1915.5 MiB)
19:14:20.188 INFO  MemoryStore - Block broadcast_1951_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1915.5 MiB)
19:14:20.188 INFO  BlockManagerInfo - Added broadcast_1951_piece0 in memory on localhost:36441 (size: 7.9 KiB, free: 1918.9 MiB)
19:14:20.189 INFO  SparkContext - Created broadcast 1951 from broadcast at ReadsSparkSink.java:133
19:14:20.192 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
19:14:20.192 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:14:20.192 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:14:20.203 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
19:14:20.203 INFO  DAGScheduler - Registering RDD 5384 (mapToPair at SparkUtils.java:161) as input to shuffle 301
19:14:20.203 INFO  DAGScheduler - Got job 551 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
19:14:20.203 INFO  DAGScheduler - Final stage: ResultStage 1215 (runJob at SparkHadoopWriter.scala:83)
19:14:20.203 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1214)
19:14:20.203 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1214)
19:14:20.203 INFO  DAGScheduler - Submitting ShuffleMapStage 1214 (MapPartitionsRDD[5384] at mapToPair at SparkUtils.java:161), which has no missing parents
19:14:20.204 INFO  MemoryStore - Block broadcast_1952 stored as values in memory (estimated size 51.5 KiB, free 1915.5 MiB)
19:14:20.205 INFO  MemoryStore - Block broadcast_1952_piece0 stored as bytes in memory (estimated size 16.8 KiB, free 1915.5 MiB)
19:14:20.205 INFO  BlockManagerInfo - Added broadcast_1952_piece0 in memory on localhost:36441 (size: 16.8 KiB, free: 1918.9 MiB)
19:14:20.205 INFO  SparkContext - Created broadcast 1952 from broadcast at DAGScheduler.scala:1580
19:14:20.205 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1214 (MapPartitionsRDD[5384] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:14:20.205 INFO  TaskSchedulerImpl - Adding task set 1214.0 with 1 tasks resource profile 0
19:14:20.205 INFO  TaskSetManager - Starting task 0.0 in stage 1214.0 (TID 1042) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:14:20.206 INFO  Executor - Running task 0.0 in stage 1214.0 (TID 1042)
19:14:20.207 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
19:14:20.207 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.210 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
19:14:20.210 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.211 INFO  Executor - Finished task 0.0 in stage 1214.0 (TID 1042). 1922 bytes result sent to driver
19:14:20.212 INFO  TaskSetManager - Finished task 0.0 in stage 1214.0 (TID 1042) in 7 ms on localhost (executor driver) (1/1)
19:14:20.212 INFO  TaskSchedulerImpl - Removed TaskSet 1214.0, whose tasks have all completed, from pool 
19:14:20.212 INFO  DAGScheduler - ShuffleMapStage 1214 (mapToPair at SparkUtils.java:161) finished in 0.008 s
19:14:20.212 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.212 INFO  DAGScheduler - running: HashSet()
19:14:20.212 INFO  DAGScheduler - waiting: HashSet(ResultStage 1215)
19:14:20.212 INFO  DAGScheduler - failed: HashSet()
19:14:20.212 INFO  DAGScheduler - Submitting ResultStage 1215 (MapPartitionsRDD[5390] at saveAsTextFile at SamSink.java:65), which has no missing parents
19:14:20.218 INFO  MemoryStore - Block broadcast_1953 stored as values in memory (estimated size 196.3 KiB, free 1915.3 MiB)
19:14:20.219 INFO  MemoryStore - Block broadcast_1953_piece0 stored as bytes in memory (estimated size 80.5 KiB, free 1915.2 MiB)
19:14:20.219 INFO  BlockManagerInfo - Added broadcast_1953_piece0 in memory on localhost:36441 (size: 80.5 KiB, free: 1918.8 MiB)
19:14:20.220 INFO  SparkContext - Created broadcast 1953 from broadcast at DAGScheduler.scala:1580
19:14:20.220 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1215 (MapPartitionsRDD[5390] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
19:14:20.220 INFO  TaskSchedulerImpl - Adding task set 1215.0 with 1 tasks resource profile 0
19:14:20.220 INFO  TaskSetManager - Starting task 0.0 in stage 1215.0 (TID 1043) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.220 INFO  Executor - Running task 0.0 in stage 1215.0 (TID 1043)
19:14:20.224 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
19:14:20.224 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.226 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
19:14:20.226 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:14:20.226 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:14:20.232 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191914204633553485065194672_5390_m_000000_0' to file:/tmp/MarkDups4172905393249932141/MarkDups.sam.parts/_temporary/0/task_202505191914204633553485065194672_5390_m_000000
19:14:20.232 INFO  SparkHadoopMapRedUtil - attempt_202505191914204633553485065194672_5390_m_000000_0: Committed. Elapsed time: 0 ms.
19:14:20.232 INFO  Executor - Finished task 0.0 in stage 1215.0 (TID 1043). 1858 bytes result sent to driver
19:14:20.233 INFO  TaskSetManager - Finished task 0.0 in stage 1215.0 (TID 1043) in 13 ms on localhost (executor driver) (1/1)
19:14:20.233 INFO  TaskSchedulerImpl - Removed TaskSet 1215.0, whose tasks have all completed, from pool 
19:14:20.233 INFO  DAGScheduler - ResultStage 1215 (runJob at SparkHadoopWriter.scala:83) finished in 0.021 s
19:14:20.233 INFO  DAGScheduler - Job 551 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.233 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1215: Stage finished
19:14:20.233 INFO  DAGScheduler - Job 551 finished: runJob at SparkHadoopWriter.scala:83, took 0.030234 s
19:14:20.233 INFO  SparkHadoopWriter - Start to commit write Job job_202505191914204633553485065194672_5390.
19:14:20.236 INFO  SparkHadoopWriter - Write Job job_202505191914204633553485065194672_5390 committed. Elapsed time: 2 ms.
19:14:20.240 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups4172905393249932141/MarkDups.sam
19:14:20.242 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups4172905393249932141/MarkDups.sam done
19:14:20.242 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 7:14:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
19:14:20.257 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:20.257 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v0192957-SNAPSHOT
19:14:20.257 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
19:14:20.257 INFO  MarkDuplicatesSpark - Executing as root@39b899212c20 on Linux v6.11.0-1014-azure amd64
19:14:20.257 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
19:14:20.257 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 7:14:20 PM GMT
19:14:20.257 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:20.257 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:20.257 INFO  MarkDuplicatesSpark - HTSJDK Version: 4.2.0-7-gb6a1842-SNAPSHOT
19:14:20.257 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
19:14:20.257 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
19:14:20.257 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
19:14:20.257 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
19:14:20.257 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
19:14:20.257 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
19:14:20.257 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
19:14:20.257 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
19:14:20.257 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
19:14:20.257 INFO  MarkDuplicatesSpark - Requester pays: disabled
19:14:20.257 INFO  MarkDuplicatesSpark - Initializing engine
19:14:20.257 INFO  MarkDuplicatesSpark - Done initializing engine
19:14:20.257 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
19:14:20.259 INFO  MemoryStore - Block broadcast_1954 stored as values in memory (estimated size 305.5 KiB, free 1914.9 MiB)
19:14:20.265 INFO  MemoryStore - Block broadcast_1954_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1914.8 MiB)
19:14:20.266 INFO  BlockManagerInfo - Added broadcast_1954_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1918.8 MiB)
19:14:20.266 INFO  SparkContext - Created broadcast 1954 from newAPIHadoopFile at PathSplitSource.java:96
19:14:20.285 INFO  MemoryStore - Block broadcast_1955 stored as values in memory (estimated size 305.5 KiB, free 1914.5 MiB)
19:14:20.291 INFO  MemoryStore - Block broadcast_1955_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1914.5 MiB)
19:14:20.291 INFO  BlockManagerInfo - Added broadcast_1955_piece0 in memory on localhost:36441 (size: 64.0 KiB, free: 1918.7 MiB)
19:14:20.292 INFO  SparkContext - Created broadcast 1955 from newAPIHadoopFile at PathSplitSource.java:96
19:14:20.322 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
19:14:20.322 INFO  FileInputFormat - Total input files to process : 1
19:14:20.323 INFO  DAGScheduler - Registering RDD 5404 (mapToPair at SparkUtils.java:161) as input to shuffle 302
19:14:20.323 INFO  DAGScheduler - Got job 552 (collect at SparkUtils.java:205) with 1 output partitions
19:14:20.323 INFO  DAGScheduler - Final stage: ResultStage 1217 (collect at SparkUtils.java:205)
19:14:20.323 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1216)
19:14:20.323 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1216)
19:14:20.323 INFO  DAGScheduler - Submitting ShuffleMapStage 1216 (MapPartitionsRDD[5404] at mapToPair at SparkUtils.java:161), which has no missing parents
19:14:20.339 INFO  MemoryStore - Block broadcast_1956 stored as values in memory (estimated size 456.1 KiB, free 1914.0 MiB)
19:14:20.342 INFO  MemoryStore - Block broadcast_1956_piece0 stored as bytes in memory (estimated size 200.0 KiB, free 1913.8 MiB)
19:14:20.342 INFO  BlockManagerInfo - Added broadcast_1956_piece0 in memory on localhost:36441 (size: 200.0 KiB, free: 1918.5 MiB)
19:14:20.342 INFO  SparkContext - Created broadcast 1956 from broadcast at DAGScheduler.scala:1580
19:14:20.342 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1216 (MapPartitionsRDD[5404] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:14:20.342 INFO  TaskSchedulerImpl - Adding task set 1216.0 with 1 tasks resource profile 0
19:14:20.342 INFO  TaskSetManager - Starting task 0.0 in stage 1216.0 (TID 1044) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9653 bytes) 
19:14:20.343 INFO  Executor - Running task 0.0 in stage 1216.0 (TID 1044)
19:14:20.370 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam:0+678
19:14:20.373 INFO  Executor - Finished task 0.0 in stage 1216.0 (TID 1044). 1148 bytes result sent to driver
19:14:20.374 INFO  TaskSetManager - Finished task 0.0 in stage 1216.0 (TID 1044) in 32 ms on localhost (executor driver) (1/1)
19:14:20.374 INFO  TaskSchedulerImpl - Removed TaskSet 1216.0, whose tasks have all completed, from pool 
19:14:20.374 INFO  DAGScheduler - ShuffleMapStage 1216 (mapToPair at SparkUtils.java:161) finished in 0.051 s
19:14:20.374 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.374 INFO  DAGScheduler - running: HashSet()
19:14:20.374 INFO  DAGScheduler - waiting: HashSet(ResultStage 1217)
19:14:20.374 INFO  DAGScheduler - failed: HashSet()
19:14:20.374 INFO  DAGScheduler - Submitting ResultStage 1217 (MapPartitionsRDD[5407] at mapPartitions at SparkUtils.java:188), which has no missing parents
19:14:20.374 INFO  MemoryStore - Block broadcast_1957 stored as values in memory (estimated size 7.4 KiB, free 1913.8 MiB)
19:14:20.375 INFO  MemoryStore - Block broadcast_1957_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1913.8 MiB)
19:14:20.375 INFO  BlockManagerInfo - Added broadcast_1957_piece0 in memory on localhost:36441 (size: 4.1 KiB, free: 1918.5 MiB)
19:14:20.375 INFO  SparkContext - Created broadcast 1957 from broadcast at DAGScheduler.scala:1580
19:14:20.375 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1217 (MapPartitionsRDD[5407] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
19:14:20.375 INFO  TaskSchedulerImpl - Adding task set 1217.0 with 1 tasks resource profile 0
19:14:20.375 INFO  TaskSetManager - Starting task 0.0 in stage 1217.0 (TID 1045) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.376 INFO  Executor - Running task 0.0 in stage 1217.0 (TID 1045)
19:14:20.376 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
19:14:20.376 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.378 INFO  Executor - Finished task 0.0 in stage 1217.0 (TID 1045). 2269 bytes result sent to driver
19:14:20.378 INFO  TaskSetManager - Finished task 0.0 in stage 1217.0 (TID 1045) in 3 ms on localhost (executor driver) (1/1)
19:14:20.378 INFO  TaskSchedulerImpl - Removed TaskSet 1217.0, whose tasks have all completed, from pool 
19:14:20.378 INFO  DAGScheduler - ResultStage 1217 (collect at SparkUtils.java:205) finished in 0.004 s
19:14:20.378 INFO  DAGScheduler - Job 552 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.378 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1217: Stage finished
19:14:20.378 INFO  DAGScheduler - Job 552 finished: collect at SparkUtils.java:205, took 0.056031 s
19:14:20.382 INFO  MemoryStore - Block broadcast_1958 stored as values in memory (estimated size 136.0 B, free 1913.8 MiB)
19:14:20.382 INFO  MemoryStore - Block broadcast_1958_piece0 stored as bytes in memory (estimated size 24.0 B, free 1913.8 MiB)
19:14:20.382 INFO  BlockManagerInfo - Added broadcast_1958_piece0 in memory on localhost:36441 (size: 24.0 B, free: 1918.5 MiB)
19:14:20.382 INFO  SparkContext - Created broadcast 1958 from broadcast at MarkDuplicatesSparkUtils.java:126
19:14:20.382 INFO  MemoryStore - Block broadcast_1959 stored as values in memory (estimated size 136.0 B, free 1913.8 MiB)
19:14:20.383 INFO  MemoryStore - Block broadcast_1959_piece0 stored as bytes in memory (estimated size 21.0 B, free 1913.8 MiB)
19:14:20.383 INFO  BlockManagerInfo - Added broadcast_1959_piece0 in memory on localhost:36441 (size: 21.0 B, free: 1918.5 MiB)
19:14:20.383 INFO  SparkContext - Created broadcast 1959 from broadcast at MarkDuplicatesSparkUtils.java:127
19:14:20.394 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
19:14:20.394 INFO  DAGScheduler - Registering RDD 5416 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 305
19:14:20.394 INFO  DAGScheduler - Registering RDD 5420 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 304
19:14:20.395 INFO  DAGScheduler - Registering RDD 5424 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 303
19:14:20.395 INFO  DAGScheduler - Got job 553 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
19:14:20.395 INFO  DAGScheduler - Final stage: ResultStage 1222 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
19:14:20.395 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1221)
19:14:20.395 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1221)
19:14:20.395 INFO  DAGScheduler - Submitting ShuffleMapStage 1219 (MapPartitionsRDD[5416] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
19:14:20.395 INFO  MemoryStore - Block broadcast_1960 stored as values in memory (estimated size 21.1 KiB, free 1913.8 MiB)
19:14:20.396 INFO  MemoryStore - Block broadcast_1960_piece0 stored as bytes in memory (estimated size 10.9 KiB, free 1913.8 MiB)
19:14:20.396 INFO  BlockManagerInfo - Added broadcast_1960_piece0 in memory on localhost:36441 (size: 10.9 KiB, free: 1918.5 MiB)
19:14:20.396 INFO  SparkContext - Created broadcast 1960 from broadcast at DAGScheduler.scala:1580
19:14:20.396 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1219 (MapPartitionsRDD[5416] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
19:14:20.396 INFO  TaskSchedulerImpl - Adding task set 1219.0 with 1 tasks resource profile 0
19:14:20.396 INFO  TaskSetManager - Starting task 0.0 in stage 1219.0 (TID 1046) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
19:14:20.397 INFO  Executor - Running task 0.0 in stage 1219.0 (TID 1046)
19:14:20.398 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
19:14:20.398 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.400 INFO  Executor - Finished task 0.0 in stage 1219.0 (TID 1046). 1879 bytes result sent to driver
19:14:20.400 INFO  TaskSetManager - Finished task 0.0 in stage 1219.0 (TID 1046) in 4 ms on localhost (executor driver) (1/1)
19:14:20.400 INFO  TaskSchedulerImpl - Removed TaskSet 1219.0, whose tasks have all completed, from pool 
19:14:20.400 INFO  DAGScheduler - ShuffleMapStage 1219 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.005 s
19:14:20.400 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.400 INFO  DAGScheduler - running: HashSet()
19:14:20.400 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1220, ShuffleMapStage 1221, ResultStage 1222)
19:14:20.400 INFO  DAGScheduler - failed: HashSet()
19:14:20.400 INFO  DAGScheduler - Submitting ShuffleMapStage 1220 (MapPartitionsRDD[5420] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
19:14:20.401 INFO  MemoryStore - Block broadcast_1961 stored as values in memory (estimated size 25.2 KiB, free 1913.8 MiB)
19:14:20.401 INFO  MemoryStore - Block broadcast_1961_piece0 stored as bytes in memory (estimated size 13.1 KiB, free 1913.8 MiB)
19:14:20.401 INFO  BlockManagerInfo - Added broadcast_1961_piece0 in memory on localhost:36441 (size: 13.1 KiB, free: 1918.5 MiB)
19:14:20.402 INFO  SparkContext - Created broadcast 1961 from broadcast at DAGScheduler.scala:1580
19:14:20.402 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1220 (MapPartitionsRDD[5420] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
19:14:20.402 INFO  TaskSchedulerImpl - Adding task set 1220.0 with 1 tasks resource profile 0
19:14:20.402 INFO  TaskSetManager - Starting task 0.0 in stage 1220.0 (TID 1047) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
19:14:20.402 INFO  Executor - Running task 0.0 in stage 1220.0 (TID 1047)
19:14:20.403 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
19:14:20.403 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.406 INFO  Executor - Finished task 0.0 in stage 1220.0 (TID 1047). 1879 bytes result sent to driver
19:14:20.406 INFO  TaskSetManager - Finished task 0.0 in stage 1220.0 (TID 1047) in 4 ms on localhost (executor driver) (1/1)
19:14:20.406 INFO  TaskSchedulerImpl - Removed TaskSet 1220.0, whose tasks have all completed, from pool 
19:14:20.406 INFO  DAGScheduler - ShuffleMapStage 1220 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.005 s
19:14:20.406 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.406 INFO  DAGScheduler - running: HashSet()
19:14:20.406 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1221, ResultStage 1222)
19:14:20.406 INFO  DAGScheduler - failed: HashSet()
19:14:20.407 INFO  DAGScheduler - Submitting ShuffleMapStage 1221 (MapPartitionsRDD[5424] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
19:14:20.407 INFO  MemoryStore - Block broadcast_1962 stored as values in memory (estimated size 15.9 KiB, free 1913.7 MiB)
19:14:20.407 INFO  MemoryStore - Block broadcast_1962_piece0 stored as bytes in memory (estimated size 8.3 KiB, free 1913.7 MiB)
19:14:20.407 INFO  BlockManagerInfo - Added broadcast_1962_piece0 in memory on localhost:36441 (size: 8.3 KiB, free: 1918.5 MiB)
19:14:20.408 INFO  SparkContext - Created broadcast 1962 from broadcast at DAGScheduler.scala:1580
19:14:20.408 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1221 (MapPartitionsRDD[5424] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
19:14:20.408 INFO  TaskSchedulerImpl - Adding task set 1221.0 with 1 tasks resource profile 0
19:14:20.408 INFO  TaskSetManager - Starting task 0.0 in stage 1221.0 (TID 1048) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:14:20.408 INFO  Executor - Running task 0.0 in stage 1221.0 (TID 1048)
19:14:20.410 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
19:14:20.410 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.411 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
19:14:20.411 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.413 INFO  Executor - Finished task 0.0 in stage 1221.0 (TID 1048). 1922 bytes result sent to driver
19:14:20.413 INFO  TaskSetManager - Finished task 0.0 in stage 1221.0 (TID 1048) in 5 ms on localhost (executor driver) (1/1)
19:14:20.413 INFO  TaskSchedulerImpl - Removed TaskSet 1221.0, whose tasks have all completed, from pool 
19:14:20.413 INFO  DAGScheduler - ShuffleMapStage 1221 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
19:14:20.413 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.413 INFO  DAGScheduler - running: HashSet()
19:14:20.413 INFO  DAGScheduler - waiting: HashSet(ResultStage 1222)
19:14:20.413 INFO  DAGScheduler - failed: HashSet()
19:14:20.413 INFO  DAGScheduler - Submitting ResultStage 1222 (MapPartitionsRDD[5426] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
19:14:20.414 INFO  MemoryStore - Block broadcast_1963 stored as values in memory (estimated size 17.1 KiB, free 1913.7 MiB)
19:14:20.414 INFO  MemoryStore - Block broadcast_1963_piece0 stored as bytes in memory (estimated size 9.0 KiB, free 1913.7 MiB)
19:14:20.414 INFO  BlockManagerInfo - Added broadcast_1963_piece0 in memory on localhost:36441 (size: 9.0 KiB, free: 1918.5 MiB)
19:14:20.414 INFO  SparkContext - Created broadcast 1963 from broadcast at DAGScheduler.scala:1580
19:14:20.414 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1222 (MapPartitionsRDD[5426] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
19:14:20.414 INFO  TaskSchedulerImpl - Adding task set 1222.0 with 1 tasks resource profile 0
19:14:20.415 INFO  TaskSetManager - Starting task 0.0 in stage 1222.0 (TID 1049) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.415 INFO  Executor - Running task 0.0 in stage 1222.0 (TID 1049)
19:14:20.416 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
19:14:20.416 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.417 INFO  Executor - Finished task 0.0 in stage 1222.0 (TID 1049). 1887 bytes result sent to driver
19:14:20.417 INFO  TaskSetManager - Finished task 0.0 in stage 1222.0 (TID 1049) in 2 ms on localhost (executor driver) (1/1)
19:14:20.417 INFO  TaskSchedulerImpl - Removed TaskSet 1222.0, whose tasks have all completed, from pool 
19:14:20.417 INFO  DAGScheduler - ResultStage 1222 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.004 s
19:14:20.417 INFO  DAGScheduler - Job 553 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.417 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1222: Stage finished
19:14:20.417 INFO  DAGScheduler - Job 553 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.023183 s
19:14:20.426 INFO  MemoryStore - Block broadcast_1964 stored as values in memory (estimated size 5.6 KiB, free 1913.7 MiB)
19:14:20.427 INFO  MemoryStore - Block broadcast_1964_piece0 stored as bytes in memory (estimated size 500.0 B, free 1913.7 MiB)
19:14:20.427 INFO  BlockManagerInfo - Added broadcast_1964_piece0 in memory on localhost:36441 (size: 500.0 B, free: 1918.5 MiB)
19:14:20.427 INFO  SparkContext - Created broadcast 1964 from broadcast at ReadsSparkSink.java:133
19:14:20.430 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
19:14:20.430 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:14:20.430 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:14:20.441 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
19:14:20.441 INFO  DAGScheduler - Registering RDD 5428 (mapToPair at SparkUtils.java:161) as input to shuffle 306
19:14:20.442 INFO  DAGScheduler - Got job 554 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
19:14:20.442 INFO  DAGScheduler - Final stage: ResultStage 1227 (runJob at SparkHadoopWriter.scala:83)
19:14:20.442 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1226)
19:14:20.442 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1226)
19:14:20.442 INFO  DAGScheduler - Submitting ShuffleMapStage 1226 (MapPartitionsRDD[5428] at mapToPair at SparkUtils.java:161), which has no missing parents
19:14:20.442 INFO  MemoryStore - Block broadcast_1965 stored as values in memory (estimated size 15.0 KiB, free 1913.7 MiB)
19:14:20.443 INFO  MemoryStore - Block broadcast_1965_piece0 stored as bytes in memory (estimated size 7.8 KiB, free 1913.7 MiB)
19:14:20.443 INFO  BlockManagerInfo - Added broadcast_1965_piece0 in memory on localhost:36441 (size: 7.8 KiB, free: 1918.5 MiB)
19:14:20.443 INFO  SparkContext - Created broadcast 1965 from broadcast at DAGScheduler.scala:1580
19:14:20.443 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1226 (MapPartitionsRDD[5428] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:14:20.443 INFO  TaskSchedulerImpl - Adding task set 1226.0 with 1 tasks resource profile 0
19:14:20.443 INFO  TaskSetManager - Starting task 0.0 in stage 1226.0 (TID 1050) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:14:20.443 INFO  Executor - Running task 0.0 in stage 1226.0 (TID 1050)
19:14:20.444 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
19:14:20.444 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.446 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
19:14:20.446 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.447 INFO  Executor - Finished task 0.0 in stage 1226.0 (TID 1050). 1879 bytes result sent to driver
19:14:20.447 INFO  TaskSetManager - Finished task 0.0 in stage 1226.0 (TID 1050) in 4 ms on localhost (executor driver) (1/1)
19:14:20.447 INFO  TaskSchedulerImpl - Removed TaskSet 1226.0, whose tasks have all completed, from pool 
19:14:20.447 INFO  DAGScheduler - ShuffleMapStage 1226 (mapToPair at SparkUtils.java:161) finished in 0.005 s
19:14:20.447 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.447 INFO  DAGScheduler - running: HashSet()
19:14:20.447 INFO  DAGScheduler - waiting: HashSet(ResultStage 1227)
19:14:20.447 INFO  DAGScheduler - failed: HashSet()
19:14:20.447 INFO  DAGScheduler - Submitting ResultStage 1227 (MapPartitionsRDD[5434] at saveAsTextFile at SamSink.java:65), which has no missing parents
19:14:20.453 INFO  MemoryStore - Block broadcast_1966 stored as values in memory (estimated size 159.8 KiB, free 1913.5 MiB)
19:14:20.454 INFO  MemoryStore - Block broadcast_1966_piece0 stored as bytes in memory (estimated size 71.6 KiB, free 1913.5 MiB)
19:14:20.454 INFO  BlockManagerInfo - Added broadcast_1966_piece0 in memory on localhost:36441 (size: 71.6 KiB, free: 1918.4 MiB)
19:14:20.454 INFO  SparkContext - Created broadcast 1966 from broadcast at DAGScheduler.scala:1580
19:14:20.454 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1227 (MapPartitionsRDD[5434] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
19:14:20.455 INFO  TaskSchedulerImpl - Adding task set 1227.0 with 1 tasks resource profile 0
19:14:20.455 INFO  TaskSetManager - Starting task 0.0 in stage 1227.0 (TID 1051) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.455 INFO  Executor - Running task 0.0 in stage 1227.0 (TID 1051)
19:14:20.458 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
19:14:20.458 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.459 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
19:14:20.459 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:14:20.459 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:14:20.465 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191914206032367666481289172_5434_m_000000_0' to file:/tmp/MarkDups6362797370792169210/MarkDups.sam.parts/_temporary/0/task_202505191914206032367666481289172_5434_m_000000
19:14:20.465 INFO  SparkHadoopMapRedUtil - attempt_202505191914206032367666481289172_5434_m_000000_0: Committed. Elapsed time: 0 ms.
19:14:20.466 INFO  Executor - Finished task 0.0 in stage 1227.0 (TID 1051). 1858 bytes result sent to driver
19:14:20.466 INFO  TaskSetManager - Finished task 0.0 in stage 1227.0 (TID 1051) in 11 ms on localhost (executor driver) (1/1)
19:14:20.466 INFO  TaskSchedulerImpl - Removed TaskSet 1227.0, whose tasks have all completed, from pool 
19:14:20.466 INFO  DAGScheduler - ResultStage 1227 (runJob at SparkHadoopWriter.scala:83) finished in 0.019 s
19:14:20.466 INFO  DAGScheduler - Job 554 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.466 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1227: Stage finished
19:14:20.466 INFO  DAGScheduler - Job 554 finished: runJob at SparkHadoopWriter.scala:83, took 0.024994 s
19:14:20.466 INFO  SparkHadoopWriter - Start to commit write Job job_202505191914206032367666481289172_5434.
19:14:20.469 INFO  SparkHadoopWriter - Write Job job_202505191914206032367666481289172_5434 committed. Elapsed time: 2 ms.
19:14:20.473 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups6362797370792169210/MarkDups.sam
19:14:20.475 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups6362797370792169210/MarkDups.sam done
19:14:20.475 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 7:14:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
19:14:20.489 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:20.489 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v0192957-SNAPSHOT
19:14:20.489 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
19:14:20.489 INFO  MarkDuplicatesSpark - Executing as root@39b899212c20 on Linux v6.11.0-1014-azure amd64
19:14:20.489 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
19:14:20.489 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 7:14:20 PM GMT
19:14:20.489 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:20.490 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
19:14:20.490 INFO  MarkDuplicatesSpark - HTSJDK Version: 4.2.0-7-gb6a1842-SNAPSHOT
19:14:20.490 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
19:14:20.490 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
19:14:20.490 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
19:14:20.490 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
19:14:20.490 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
19:14:20.490 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
19:14:20.490 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
19:14:20.490 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
19:14:20.490 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
19:14:20.490 INFO  MarkDuplicatesSpark - Requester pays: disabled
19:14:20.490 INFO  MarkDuplicatesSpark - Initializing engine
19:14:20.490 INFO  MarkDuplicatesSpark - Done initializing engine
19:14:20.490 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
19:14:20.492 INFO  MemoryStore - Block broadcast_1967 stored as values in memory (estimated size 305.5 KiB, free 1913.2 MiB)
19:14:20.499 INFO  MemoryStore - Block broadcast_1967_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1913.1 MiB)
19:14:20.499 INFO  BlockManagerInfo - Added broadcast_1967_piece0 in memory on localhost:36441 (size: 64.1 KiB, free: 1918.3 MiB)
19:14:20.499 INFO  SparkContext - Created broadcast 1967 from newAPIHadoopFile at PathSplitSource.java:96
19:14:20.519 INFO  MemoryStore - Block broadcast_1968 stored as values in memory (estimated size 305.5 KiB, free 1912.8 MiB)
19:14:20.525 INFO  MemoryStore - Block broadcast_1968_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1912.7 MiB)
19:14:20.525 INFO  BlockManagerInfo - Added broadcast_1968_piece0 in memory on localhost:36441 (size: 64.1 KiB, free: 1918.3 MiB)
19:14:20.526 INFO  SparkContext - Created broadcast 1968 from newAPIHadoopFile at PathSplitSource.java:96
19:14:20.557 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
19:14:20.557 INFO  FileInputFormat - Total input files to process : 1
19:14:20.557 INFO  DAGScheduler - Registering RDD 5448 (mapToPair at SparkUtils.java:161) as input to shuffle 307
19:14:20.558 INFO  DAGScheduler - Got job 555 (collect at SparkUtils.java:205) with 1 output partitions
19:14:20.558 INFO  DAGScheduler - Final stage: ResultStage 1229 (collect at SparkUtils.java:205)
19:14:20.558 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1228)
19:14:20.558 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1228)
19:14:20.558 INFO  DAGScheduler - Submitting ShuffleMapStage 1228 (MapPartitionsRDD[5448] at mapToPair at SparkUtils.java:161), which has no missing parents
19:14:20.574 INFO  MemoryStore - Block broadcast_1969 stored as values in memory (estimated size 480.2 KiB, free 1912.3 MiB)
19:14:20.577 INFO  MemoryStore - Block broadcast_1969_piece0 stored as bytes in memory (estimated size 206.2 KiB, free 1912.1 MiB)
19:14:20.577 INFO  BlockManagerInfo - Added broadcast_1969_piece0 in memory on localhost:36441 (size: 206.2 KiB, free: 1918.1 MiB)
19:14:20.577 INFO  SparkContext - Created broadcast 1969 from broadcast at DAGScheduler.scala:1580
19:14:20.577 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1228 (MapPartitionsRDD[5448] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:14:20.577 INFO  TaskSchedulerImpl - Adding task set 1228.0 with 1 tasks resource profile 0
19:14:20.578 INFO  TaskSetManager - Starting task 0.0 in stage 1228.0 (TID 1052) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9673 bytes) 
19:14:20.578 INFO  Executor - Running task 0.0 in stage 1228.0 (TID 1052)
19:14:20.605 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam:0+5416
19:14:20.610 INFO  Executor - Finished task 0.0 in stage 1228.0 (TID 1052). 1148 bytes result sent to driver
19:14:20.611 INFO  TaskSetManager - Finished task 0.0 in stage 1228.0 (TID 1052) in 34 ms on localhost (executor driver) (1/1)
19:14:20.611 INFO  TaskSchedulerImpl - Removed TaskSet 1228.0, whose tasks have all completed, from pool 
19:14:20.611 INFO  DAGScheduler - ShuffleMapStage 1228 (mapToPair at SparkUtils.java:161) finished in 0.053 s
19:14:20.611 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.611 INFO  DAGScheduler - running: HashSet()
19:14:20.611 INFO  DAGScheduler - waiting: HashSet(ResultStage 1229)
19:14:20.611 INFO  DAGScheduler - failed: HashSet()
19:14:20.611 INFO  DAGScheduler - Submitting ResultStage 1229 (MapPartitionsRDD[5451] at mapPartitions at SparkUtils.java:188), which has no missing parents
19:14:20.611 INFO  MemoryStore - Block broadcast_1970 stored as values in memory (estimated size 7.4 KiB, free 1912.1 MiB)
19:14:20.612 INFO  MemoryStore - Block broadcast_1970_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1912.1 MiB)
19:14:20.612 INFO  BlockManagerInfo - Added broadcast_1970_piece0 in memory on localhost:36441 (size: 4.1 KiB, free: 1918.1 MiB)
19:14:20.612 INFO  SparkContext - Created broadcast 1970 from broadcast at DAGScheduler.scala:1580
19:14:20.612 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1229 (MapPartitionsRDD[5451] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
19:14:20.612 INFO  TaskSchedulerImpl - Adding task set 1229.0 with 1 tasks resource profile 0
19:14:20.612 INFO  TaskSetManager - Starting task 0.0 in stage 1229.0 (TID 1053) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.612 INFO  Executor - Running task 0.0 in stage 1229.0 (TID 1053)
19:14:20.613 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
19:14:20.613 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.615 INFO  Executor - Finished task 0.0 in stage 1229.0 (TID 1053). 2039 bytes result sent to driver
19:14:20.615 INFO  TaskSetManager - Finished task 0.0 in stage 1229.0 (TID 1053) in 3 ms on localhost (executor driver) (1/1)
19:14:20.615 INFO  TaskSchedulerImpl - Removed TaskSet 1229.0, whose tasks have all completed, from pool 
19:14:20.615 INFO  DAGScheduler - ResultStage 1229 (collect at SparkUtils.java:205) finished in 0.004 s
19:14:20.615 INFO  DAGScheduler - Job 555 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.615 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1229: Stage finished
19:14:20.615 INFO  DAGScheduler - Job 555 finished: collect at SparkUtils.java:205, took 0.058454 s
19:14:20.619 INFO  MemoryStore - Block broadcast_1971 stored as values in memory (estimated size 392.0 B, free 1912.1 MiB)
19:14:20.619 INFO  MemoryStore - Block broadcast_1971_piece0 stored as bytes in memory (estimated size 33.0 B, free 1912.1 MiB)
19:14:20.619 INFO  BlockManagerInfo - Added broadcast_1971_piece0 in memory on localhost:36441 (size: 33.0 B, free: 1918.1 MiB)
19:14:20.619 INFO  SparkContext - Created broadcast 1971 from broadcast at MarkDuplicatesSparkUtils.java:126
19:14:20.620 INFO  MemoryStore - Block broadcast_1972 stored as values in memory (estimated size 144.0 B, free 1912.1 MiB)
19:14:20.620 INFO  MemoryStore - Block broadcast_1972_piece0 stored as bytes in memory (estimated size 28.0 B, free 1912.1 MiB)
19:14:20.620 INFO  BlockManagerInfo - Added broadcast_1972_piece0 in memory on localhost:36441 (size: 28.0 B, free: 1918.1 MiB)
19:14:20.620 INFO  SparkContext - Created broadcast 1972 from broadcast at MarkDuplicatesSparkUtils.java:127
19:14:20.632 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
19:14:20.633 INFO  DAGScheduler - Registering RDD 5460 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 310
19:14:20.633 INFO  DAGScheduler - Registering RDD 5464 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 309
19:14:20.633 INFO  DAGScheduler - Registering RDD 5468 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 308
19:14:20.633 INFO  DAGScheduler - Got job 556 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
19:14:20.633 INFO  DAGScheduler - Final stage: ResultStage 1234 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
19:14:20.633 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1233)
19:14:20.633 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1233)
19:14:20.633 INFO  DAGScheduler - Submitting ShuffleMapStage 1231 (MapPartitionsRDD[5460] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
19:14:20.634 INFO  MemoryStore - Block broadcast_1973 stored as values in memory (estimated size 45.2 KiB, free 1912.0 MiB)
19:14:20.635 INFO  MemoryStore - Block broadcast_1973_piece0 stored as bytes in memory (estimated size 17.1 KiB, free 1912.0 MiB)
19:14:20.635 INFO  BlockManagerInfo - Added broadcast_1973_piece0 in memory on localhost:36441 (size: 17.1 KiB, free: 1918.1 MiB)
19:14:20.635 INFO  SparkContext - Created broadcast 1973 from broadcast at DAGScheduler.scala:1580
19:14:20.635 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1231 (MapPartitionsRDD[5460] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
19:14:20.635 INFO  TaskSchedulerImpl - Adding task set 1231.0 with 1 tasks resource profile 0
19:14:20.635 INFO  TaskSetManager - Starting task 0.0 in stage 1231.0 (TID 1054) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
19:14:20.636 INFO  Executor - Running task 0.0 in stage 1231.0 (TID 1054)
19:14:20.637 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
19:14:20.637 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.639 INFO  Executor - Finished task 0.0 in stage 1231.0 (TID 1054). 1922 bytes result sent to driver
19:14:20.640 INFO  TaskSetManager - Finished task 0.0 in stage 1231.0 (TID 1054) in 5 ms on localhost (executor driver) (1/1)
19:14:20.640 INFO  TaskSchedulerImpl - Removed TaskSet 1231.0, whose tasks have all completed, from pool 
19:14:20.640 INFO  DAGScheduler - ShuffleMapStage 1231 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
19:14:20.640 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.640 INFO  DAGScheduler - running: HashSet()
19:14:20.640 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1232, ShuffleMapStage 1233, ResultStage 1234)
19:14:20.640 INFO  DAGScheduler - failed: HashSet()
19:14:20.640 INFO  DAGScheduler - Submitting ShuffleMapStage 1232 (MapPartitionsRDD[5464] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
19:14:20.641 INFO  MemoryStore - Block broadcast_1974 stored as values in memory (estimated size 49.3 KiB, free 1911.9 MiB)
19:14:20.641 INFO  MemoryStore - Block broadcast_1974_piece0 stored as bytes in memory (estimated size 19.3 KiB, free 1911.9 MiB)
19:14:20.641 INFO  BlockManagerInfo - Added broadcast_1974_piece0 in memory on localhost:36441 (size: 19.3 KiB, free: 1918.0 MiB)
19:14:20.642 INFO  SparkContext - Created broadcast 1974 from broadcast at DAGScheduler.scala:1580
19:14:20.642 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1232 (MapPartitionsRDD[5464] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
19:14:20.642 INFO  TaskSchedulerImpl - Adding task set 1232.0 with 1 tasks resource profile 0
19:14:20.642 INFO  TaskSetManager - Starting task 0.0 in stage 1232.0 (TID 1055) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
19:14:20.642 INFO  Executor - Running task 0.0 in stage 1232.0 (TID 1055)
19:14:20.644 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
19:14:20.644 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.647 INFO  Executor - Finished task 0.0 in stage 1232.0 (TID 1055). 1922 bytes result sent to driver
19:14:20.647 INFO  TaskSetManager - Finished task 0.0 in stage 1232.0 (TID 1055) in 5 ms on localhost (executor driver) (1/1)
19:14:20.647 INFO  TaskSchedulerImpl - Removed TaskSet 1232.0, whose tasks have all completed, from pool 
19:14:20.647 INFO  DAGScheduler - ShuffleMapStage 1232 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
19:14:20.647 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.647 INFO  DAGScheduler - running: HashSet()
19:14:20.647 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1233, ResultStage 1234)
19:14:20.647 INFO  DAGScheduler - failed: HashSet()
19:14:20.647 INFO  DAGScheduler - Submitting ShuffleMapStage 1233 (MapPartitionsRDD[5468] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
19:14:20.648 INFO  MemoryStore - Block broadcast_1975 stored as values in memory (estimated size 40.0 KiB, free 1911.9 MiB)
19:14:20.648 INFO  MemoryStore - Block broadcast_1975_piece0 stored as bytes in memory (estimated size 14.5 KiB, free 1911.9 MiB)
19:14:20.648 INFO  BlockManagerInfo - Added broadcast_1975_piece0 in memory on localhost:36441 (size: 14.5 KiB, free: 1918.0 MiB)
19:14:20.649 INFO  SparkContext - Created broadcast 1975 from broadcast at DAGScheduler.scala:1580
19:14:20.649 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1233 (MapPartitionsRDD[5468] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
19:14:20.649 INFO  TaskSchedulerImpl - Adding task set 1233.0 with 1 tasks resource profile 0
19:14:20.649 INFO  TaskSetManager - Starting task 0.0 in stage 1233.0 (TID 1056) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:14:20.649 INFO  Executor - Running task 0.0 in stage 1233.0 (TID 1056)
19:14:20.650 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
19:14:20.650 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.652 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
19:14:20.652 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.653 INFO  Executor - Finished task 0.0 in stage 1233.0 (TID 1056). 1879 bytes result sent to driver
19:14:20.653 INFO  TaskSetManager - Finished task 0.0 in stage 1233.0 (TID 1056) in 4 ms on localhost (executor driver) (1/1)
19:14:20.653 INFO  TaskSchedulerImpl - Removed TaskSet 1233.0, whose tasks have all completed, from pool 
19:14:20.653 INFO  DAGScheduler - ShuffleMapStage 1233 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
19:14:20.653 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.653 INFO  DAGScheduler - running: HashSet()
19:14:20.653 INFO  DAGScheduler - waiting: HashSet(ResultStage 1234)
19:14:20.653 INFO  DAGScheduler - failed: HashSet()
19:14:20.653 INFO  DAGScheduler - Submitting ResultStage 1234 (MapPartitionsRDD[5470] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
19:14:20.654 INFO  MemoryStore - Block broadcast_1976 stored as values in memory (estimated size 41.2 KiB, free 1911.8 MiB)
19:14:20.654 INFO  MemoryStore - Block broadcast_1976_piece0 stored as bytes in memory (estimated size 15.3 KiB, free 1911.8 MiB)
19:14:20.654 INFO  BlockManagerInfo - Added broadcast_1976_piece0 in memory on localhost:36441 (size: 15.3 KiB, free: 1918.0 MiB)
19:14:20.654 INFO  SparkContext - Created broadcast 1976 from broadcast at DAGScheduler.scala:1580
19:14:20.655 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1234 (MapPartitionsRDD[5470] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
19:14:20.655 INFO  TaskSchedulerImpl - Adding task set 1234.0 with 1 tasks resource profile 0
19:14:20.655 INFO  TaskSetManager - Starting task 0.0 in stage 1234.0 (TID 1057) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.655 INFO  Executor - Running task 0.0 in stage 1234.0 (TID 1057)
19:14:20.656 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
19:14:20.656 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.657 INFO  Executor - Finished task 0.0 in stage 1234.0 (TID 1057). 1901 bytes result sent to driver
19:14:20.657 INFO  TaskSetManager - Finished task 0.0 in stage 1234.0 (TID 1057) in 2 ms on localhost (executor driver) (1/1)
19:14:20.657 INFO  TaskSchedulerImpl - Removed TaskSet 1234.0, whose tasks have all completed, from pool 
19:14:20.657 INFO  DAGScheduler - ResultStage 1234 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.004 s
19:14:20.658 INFO  DAGScheduler - Job 556 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.658 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1234: Stage finished
19:14:20.658 INFO  DAGScheduler - Job 556 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.025245 s
19:14:20.668 INFO  MemoryStore - Block broadcast_1977 stored as values in memory (estimated size 93.5 KiB, free 1911.7 MiB)
19:14:20.668 INFO  MemoryStore - Block broadcast_1977_piece0 stored as bytes in memory (estimated size 5.6 KiB, free 1911.7 MiB)
19:14:20.668 INFO  BlockManagerInfo - Added broadcast_1977_piece0 in memory on localhost:36441 (size: 5.6 KiB, free: 1918.0 MiB)
19:14:20.668 INFO  SparkContext - Created broadcast 1977 from broadcast at ReadsSparkSink.java:133
19:14:20.672 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
19:14:20.672 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:14:20.672 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:14:20.683 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
19:14:20.683 INFO  DAGScheduler - Registering RDD 5472 (mapToPair at SparkUtils.java:161) as input to shuffle 311
19:14:20.683 INFO  DAGScheduler - Got job 557 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
19:14:20.683 INFO  DAGScheduler - Final stage: ResultStage 1239 (runJob at SparkHadoopWriter.scala:83)
19:14:20.683 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1238)
19:14:20.683 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1238)
19:14:20.683 INFO  DAGScheduler - Submitting ShuffleMapStage 1238 (MapPartitionsRDD[5472] at mapToPair at SparkUtils.java:161), which has no missing parents
19:14:20.684 INFO  MemoryStore - Block broadcast_1978 stored as values in memory (estimated size 39.1 KiB, free 1911.7 MiB)
19:14:20.684 INFO  MemoryStore - Block broadcast_1978_piece0 stored as bytes in memory (estimated size 14.1 KiB, free 1911.7 MiB)
19:14:20.685 INFO  BlockManagerInfo - Added broadcast_1978_piece0 in memory on localhost:36441 (size: 14.1 KiB, free: 1918.0 MiB)
19:14:20.685 INFO  SparkContext - Created broadcast 1978 from broadcast at DAGScheduler.scala:1580
19:14:20.685 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1238 (MapPartitionsRDD[5472] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
19:14:20.685 INFO  TaskSchedulerImpl - Adding task set 1238.0 with 1 tasks resource profile 0
19:14:20.685 INFO  TaskSetManager - Starting task 0.0 in stage 1238.0 (TID 1058) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
19:14:20.685 INFO  Executor - Running task 0.0 in stage 1238.0 (TID 1058)
19:14:20.687 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
19:14:20.687 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.688 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
19:14:20.688 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.689 INFO  Executor - Finished task 0.0 in stage 1238.0 (TID 1058). 1879 bytes result sent to driver
19:14:20.689 INFO  TaskSetManager - Finished task 0.0 in stage 1238.0 (TID 1058) in 4 ms on localhost (executor driver) (1/1)
19:14:20.689 INFO  TaskSchedulerImpl - Removed TaskSet 1238.0, whose tasks have all completed, from pool 
19:14:20.690 INFO  DAGScheduler - ShuffleMapStage 1238 (mapToPair at SparkUtils.java:161) finished in 0.005 s
19:14:20.690 INFO  DAGScheduler - looking for newly runnable stages
19:14:20.690 INFO  DAGScheduler - running: HashSet()
19:14:20.690 INFO  DAGScheduler - waiting: HashSet(ResultStage 1239)
19:14:20.690 INFO  DAGScheduler - failed: HashSet()
19:14:20.690 INFO  DAGScheduler - Submitting ResultStage 1239 (MapPartitionsRDD[5478] at saveAsTextFile at SamSink.java:65), which has no missing parents
19:14:20.696 INFO  MemoryStore - Block broadcast_1979 stored as values in memory (estimated size 183.9 KiB, free 1911.5 MiB)
19:14:20.697 INFO  MemoryStore - Block broadcast_1979_piece0 stored as bytes in memory (estimated size 77.7 KiB, free 1911.4 MiB)
19:14:20.697 INFO  BlockManagerInfo - Added broadcast_1979_piece0 in memory on localhost:36441 (size: 77.7 KiB, free: 1917.9 MiB)
19:14:20.697 INFO  SparkContext - Created broadcast 1979 from broadcast at DAGScheduler.scala:1580
19:14:20.697 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1239 (MapPartitionsRDD[5478] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
19:14:20.697 INFO  TaskSchedulerImpl - Adding task set 1239.0 with 1 tasks resource profile 0
19:14:20.697 INFO  TaskSetManager - Starting task 0.0 in stage 1239.0 (TID 1059) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
19:14:20.698 INFO  Executor - Running task 0.0 in stage 1239.0 (TID 1059)
19:14:20.701 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
19:14:20.701 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
19:14:20.702 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
19:14:20.702 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
19:14:20.702 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
19:14:20.708 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191914203786810329526736406_5478_m_000000_0' to file:/tmp/MarkDups16528098551079121494/MarkDups.sam.parts/_temporary/0/task_202505191914203786810329526736406_5478_m_000000
19:14:20.708 INFO  SparkHadoopMapRedUtil - attempt_202505191914203786810329526736406_5478_m_000000_0: Committed. Elapsed time: 0 ms.
19:14:20.708 INFO  Executor - Finished task 0.0 in stage 1239.0 (TID 1059). 1858 bytes result sent to driver
19:14:20.709 INFO  TaskSetManager - Finished task 0.0 in stage 1239.0 (TID 1059) in 12 ms on localhost (executor driver) (1/1)
19:14:20.709 INFO  TaskSchedulerImpl - Removed TaskSet 1239.0, whose tasks have all completed, from pool 
19:14:20.709 INFO  DAGScheduler - ResultStage 1239 (runJob at SparkHadoopWriter.scala:83) finished in 0.019 s
19:14:20.709 INFO  DAGScheduler - Job 557 is finished. Cancelling potential speculative or zombie tasks for this job
19:14:20.709 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1239: Stage finished
19:14:20.709 INFO  DAGScheduler - Job 557 finished: runJob at SparkHadoopWriter.scala:83, took 0.026044 s
19:14:20.709 INFO  SparkHadoopWriter - Start to commit write Job job_202505191914203786810329526736406_5478.
19:14:20.712 INFO  SparkHadoopWriter - Write Job job_202505191914203786810329526736406_5478 committed. Elapsed time: 2 ms.
19:14:20.716 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups16528098551079121494/MarkDups.sam
19:14:20.718 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups16528098551079121494/MarkDups.sam done
19:14:20.718 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 7:14:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
19:14:20.739 INFO  BlockManagerInfo - Removed broadcast_1929_piece0 on localhost:36441 in memory (size: 64.0 KiB, free: 1918.0 MiB)
19:14:20.739 INFO  BlockManagerInfo - Removed broadcast_1943_piece0 on localhost:36441 in memory (size: 208.9 KiB, free: 1918.2 MiB)
19:14:20.739 INFO  BlockManagerInfo - Removed broadcast_1955_piece0 on localhost:36441 in memory (size: 64.0 KiB, free: 1918.2 MiB)
19:14:20.740 INFO  BlockManagerInfo - Removed broadcast_1932_piece0 on localhost:36441 in memory (size: 19.0 B, free: 1918.2 MiB)
19:14:20.740 INFO  BlockManagerInfo - Removed broadcast_1947_piece0 on localhost:36441 in memory (size: 19.8 KiB, free: 1918.3 MiB)
19:14:20.740 INFO  BlockManagerInfo - Removed broadcast_1973_piece0 on localhost:36441 in memory (size: 17.1 KiB, free: 1918.3 MiB)
19:14:20.741 INFO  BlockManagerInfo - Removed broadcast_1962_piece0 on localhost:36441 in memory (size: 8.3 KiB, free: 1918.3 MiB)
19:14:20.741 INFO  BlockManagerInfo - Removed broadcast_1935_piece0 on localhost:36441 in memory (size: 13.2 KiB, free: 1918.3 MiB)
19:14:20.741 INFO  BlockManagerInfo - Removed broadcast_1966_piece0 on localhost:36441 in memory (size: 71.6 KiB, free: 1918.4 MiB)
19:14:20.741 INFO  BlockManagerInfo - Removed broadcast_1976_piece0 on localhost:36441 in memory (size: 15.3 KiB, free: 1918.4 MiB)
19:14:20.742 INFO  BlockManagerInfo - Removed broadcast_1928_piece0 on localhost:36441 in memory (size: 64.0 KiB, free: 1918.4 MiB)
19:14:20.742 INFO  BlockManagerInfo - Removed broadcast_1971_piece0 on localhost:36441 in memory (size: 33.0 B, free: 1918.4 MiB)
19:14:20.742 INFO  BlockManagerInfo - Removed broadcast_1961_piece0 on localhost:36441 in memory (size: 13.1 KiB, free: 1918.5 MiB)
19:14:20.743 INFO  BlockManagerInfo - Removed broadcast_1958_piece0 on localhost:36441 in memory (size: 24.0 B, free: 1918.5 MiB)
19:14:20.743 INFO  BlockManagerInfo - Removed broadcast_1963_piece0 on localhost:36441 in memory (size: 9.0 KiB, free: 1918.5 MiB)
19:14:20.743 INFO  BlockManagerInfo - Removed broadcast_1941_piece0 on localhost:36441 in memory (size: 64.0 KiB, free: 1918.5 MiB)
19:14:20.744 INFO  BlockManagerInfo - Removed broadcast_1930_piece0 on localhost:36441 in memory (size: 200.3 KiB, free: 1918.7 MiB)
19:14:20.744 INFO  BlockManagerInfo - Removed broadcast_1942_piece0 on localhost:36441 in memory (size: 64.0 KiB, free: 1918.8 MiB)
19:14:20.744 INFO  BlockManagerInfo - Removed broadcast_1956_piece0 on localhost:36441 in memory (size: 200.0 KiB, free: 1919.0 MiB)
19:14:20.745 INFO  BlockManagerInfo - Removed broadcast_1974_piece0 on localhost:36441 in memory (size: 19.3 KiB, free: 1919.0 MiB)
19:14:20.745 INFO  BlockManagerInfo - Removed broadcast_1940_piece0 on localhost:36441 in memory (size: 71.6 KiB, free: 1919.1 MiB)
19:14:20.746 INFO  BlockManagerInfo - Removed broadcast_1933_piece0 on localhost:36441 in memory (size: 31.0 B, free: 1919.1 MiB)
19:14:20.746 INFO  BlockManagerInfo - Removed broadcast_1938_piece0 on localhost:36441 in memory (size: 663.0 B, free: 1919.1 MiB)
19:14:20.746 INFO  BlockManagerInfo - Removed broadcast_1954_piece0 on localhost:36441 in memory (size: 64.0 KiB, free: 1919.1 MiB)
19:14:20.747 INFO  BlockManagerInfo - Removed broadcast_1968_piece0 on localhost:36441 in memory (size: 64.1 KiB, free: 1919.2 MiB)
19:14:20.747 INFO  BlockManagerInfo - Removed broadcast_1952_piece0 on localhost:36441 in memory (size: 16.8 KiB, free: 1919.2 MiB)
19:14:20.747 INFO  BlockManagerInfo - Removed broadcast_1975_piece0 on localhost:36441 in memory (size: 14.5 KiB, free: 1919.2 MiB)
19:14:20.747 INFO  BlockManagerInfo - Removed broadcast_1937_piece0 on localhost:36441 in memory (size: 9.1 KiB, free: 1919.2 MiB)
19:14:20.748 INFO  BlockManagerInfo - Removed broadcast_1931_piece0 on localhost:36441 in memory (size: 4.1 KiB, free: 1919.2 MiB)
19:14:20.748 INFO  BlockManagerInfo - Removed broadcast_1979_piece0 on localhost:36441 in memory (size: 77.7 KiB, free: 1919.3 MiB)
19:14:20.749 INFO  BlockManagerInfo - Removed broadcast_1936_piece0 on localhost:36441 in memory (size: 8.5 KiB, free: 1919.3 MiB)
19:14:20.749 INFO  BlockManagerInfo - Removed broadcast_1951_piece0 on localhost:36441 in memory (size: 7.9 KiB, free: 1919.3 MiB)
19:14:20.749 INFO  BlockManagerInfo - Removed broadcast_1964_piece0 on localhost:36441 in memory (size: 500.0 B, free: 1919.3 MiB)
19:14:20.751 INFO  BlockManagerInfo - Removed broadcast_1948_piece0 on localhost:36441 in memory (size: 22.0 KiB, free: 1919.4 MiB)
19:14:20.751 INFO  BlockManagerInfo - Removed broadcast_1970_piece0 on localhost:36441 in memory (size: 4.1 KiB, free: 1919.4 MiB)
19:14:20.752 INFO  BlockManagerInfo - Removed broadcast_1944_piece0 on localhost:36441 in memory (size: 4.1 KiB, free: 1919.4 MiB)
19:14:20.752 INFO  BlockManagerInfo - Removed broadcast_1959_piece0 on localhost:36441 in memory (size: 21.0 B, free: 1919.4 MiB)
19:14:20.752 INFO  BlockManagerInfo - Removed broadcast_1957_piece0 on localhost:36441 in memory (size: 4.1 KiB, free: 1919.4 MiB)
19:14:20.753 INFO  BlockManagerInfo - Removed broadcast_1978_piece0 on localhost:36441 in memory (size: 14.1 KiB, free: 1919.4 MiB)
19:14:20.753 INFO  BlockManagerInfo - Removed broadcast_1953_piece0 on localhost:36441 in memory (size: 80.5 KiB, free: 1919.5 MiB)
19:14:20.753 INFO  BlockManagerInfo - Removed broadcast_1960_piece0 on localhost:36441 in memory (size: 10.9 KiB, free: 1919.5 MiB)
19:14:20.753 INFO  BlockManagerInfo - Removed broadcast_1934_piece0 on localhost:36441 in memory (size: 11.2 KiB, free: 1919.5 MiB)
19:14:20.754 INFO  BlockManagerInfo - Removed broadcast_1949_piece0 on localhost:36441 in memory (size: 17.3 KiB, free: 1919.5 MiB)
19:14:20.754 INFO  BlockManagerInfo - Removed broadcast_1939_piece0 on localhost:36441 in memory (size: 8.0 KiB, free: 1919.5 MiB)
19:14:20.754 INFO  BlockManagerInfo - Removed broadcast_1946_piece0 on localhost:36441 in memory (size: 209.0 B, free: 1919.5 MiB)
19:14:20.755 INFO  BlockManagerInfo - Removed broadcast_1969_piece0 on localhost:36441 in memory (size: 206.2 KiB, free: 1919.7 MiB)
19:14:20.755 INFO  BlockManagerInfo - Removed broadcast_1965_piece0 on localhost:36441 in memory (size: 7.8 KiB, free: 1919.7 MiB)
19:14:20.756 INFO  BlockManagerInfo - Removed broadcast_1977_piece0 on localhost:36441 in memory (size: 5.6 KiB, free: 1919.7 MiB)
19:14:20.756 INFO  BlockManagerInfo - Removed broadcast_1972_piece0 on localhost:36441 in memory (size: 28.0 B, free: 1919.7 MiB)
19:14:20.756 INFO  BlockManagerInfo - Removed broadcast_1950_piece0 on localhost:36441 in memory (size: 18.0 KiB, free: 1919.7 MiB)
19:14:20.757 INFO  BlockManagerInfo - Removed broadcast_1945_piece0 on localhost:36441 in memory (size: 540.0 B, free: 1919.7 MiB)
19:14:20.757 INFO  BlockManagerInfo - Removed broadcast_1967_piece0 on localhost:36441 in memory (size: 64.1 KiB, free: 1919.8 MiB)
[May 19, 2025 at 7:14:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
19:14:26.316 ERROR Executor - Exception in task 0.0 in stage 1459.0 (TID 1206)
org.broadinstitute.hellbender.exceptions.UserException$ReadMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 is missing the read group (RG) tag, which is required by the GATK.  Please use http://gatkforums.broadinstitute.org/discussion/59/companion-utilities-replacereadgroups to fix this problem
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:64) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
19:14:26.330 ERROR TaskSetManager - Task 0 in stage 1459.0 failed 1 times; aborting job
[May 19, 2025 at 7:14:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
19:14:26.562 ERROR Executor - Exception in task 0.0 in stage 1466.0 (TID 1209)
org.broadinstitute.hellbender.exceptions.UserException$HeaderMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 contains an (RG) tag with the group NotADuplicateGroup which is not found in the file header.
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:66) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-0192957-SNAPSHOT-local.jar:0192957-SNAPSHOT]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
19:14:26.564 ERROR TaskSetManager - Task 0 in stage 1466.0 failed 1 times; aborting job
[May 19, 2025 at 7:14:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184
[May 19, 2025 at 7:14:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1713373184