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

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

tests
0

failures
0

ignored
1m1.40s

duration
100%

successful

Tests

Test Duration Result
assertThatExpectedOutputUpdateToggleIsDisabled 0s passed
testAssertAssumeUnsortedFilesAreQueryGroupedFiles 0.565s passed
testAssertCorrectSortOrderMultipleBams 0.156s passed
testAssertCorrectSortOrderMultipleBamsOverriding 0.482s passed
testBulkFragmentsNoDuplicates 1.213s passed
testBulkFragmentsWithDuplicates 2.126s passed
testDifferentChromosomesInOppositeOrder 0.303s 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.283s 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.251s 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.262s passed
testFlowModeFlag 1.661s passed
testHashCollisionHandling 1.082s 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.311s 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.288s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[0](true, true, true) 0.315s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[1](true, false, true) 0.321s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[2](false, true, true) 0.311s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[3](true, true, false) 0.308s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[4](true, false, false) 0.312s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[5](false, true, false) 0.324s passed
testMappedFragmentAndMappedPairFirstOfPairNonPrimary 0.300s passed
testMappedFragmentAndMatePairFirstUnmapped 0.309s passed
testMappedFragmentAndMatePairSecondUnmapped 0.313s passed
testMappedPairAndMappedFragmentAndMatePairFirstUnmapped 0.307s passed
testMappedPairAndMappedFragmentAndMatePairSecondUnmapped 0.318s passed
testMappedPairAndMatePairFirstOppositeStrandSecondUnmapped 0.328s passed
testMappedPairAndMatePairFirstUnmapped 0.316s passed
testMappedPairAndMatePairSecondUnmapped 0.309s passed
testMappedPairWithFirstEndSamePositionAndOther 0.312s passed
testMappedPairWithSamePosition 0.314s passed
testMappedPairWithSamePositionSameCigar 0.315s passed
testMarkDuplicatesSparkDeletingDuplicateReads[0]([Ljava.io.File;@5fa4715a, 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.372s passed
testMarkDuplicatesSparkDeletingDuplicateReads[1]([Ljava.io.File;@47ba9067, 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;@3a58ec06, 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.381s passed
testMarkDuplicatesSparkDeletingDuplicateReads[3]([Ljava.io.File;@55980c5f, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.338s passed
testMarkDuplicatesSparkDeletingDuplicateReads[4]([Ljava.io.File;@31aa864f, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.355s passed
testMarkDuplicatesSparkDeletingDuplicateReads[5]([Ljava.io.File;@424c732b, 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.191s passed
testMarkDuplicatesSparkDeletingDuplicateReads[6]([Ljava.io.File;@5b0984c7, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 1.217s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[0]([Ljava.io.File;@54f1dfe2, 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.363s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[1]([Ljava.io.File;@36db3fe0, 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.420s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[2]([Ljava.io.File;@6a79abd8, 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.432s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[3]([Ljava.io.File;@1bdc64f5, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.358s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[4]([Ljava.io.File;@bd182c1, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.341s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[5]([Ljava.io.File;@7c383611, 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.167s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[6]([Ljava.io.File;@7da5a7ab, 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.155s passed
testMarkDuplicatesSparkIntegrationTestLocal[0]([Ljava.io.File;@1fe6be3f, 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.363s passed
testMarkDuplicatesSparkIntegrationTestLocal[1]([Ljava.io.File;@3416e97b, 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.363s passed
testMarkDuplicatesSparkIntegrationTestLocal[2]([Ljava.io.File;@639574bb, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.372s passed
testMarkDuplicatesSparkIntegrationTestLocal[3]([Ljava.io.File;@6c27dca7, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.331s passed
testMarkDuplicatesSparkIntegrationTestLocal[4]([Ljava.io.File;@3fc5c06, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.343s passed
testMarkDuplicatesSparkIntegrationTestLocal[5]([Ljava.io.File;@7c1e6103, 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.151s passed
testMarkDuplicatesSparkIntegrationTestLocal[6]([Ljava.io.File;@69ae3c2e, 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.215s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[0]([Ljava.io.File;@29ed7e4, 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.345s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[1]([Ljava.io.File;@6b06a881, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.367s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[2]([Ljava.io.File;@423e1f1b, 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.365s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[3]([Ljava.io.File;@296630e5, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.350s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[4]([Ljava.io.File;@189969ad, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.349s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[5]([Ljava.io.File;@58eb24dc, 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.129s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[6]([Ljava.io.File;@6469aabd, 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.149s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[0]([Ljava.io.File;@681d8293, 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;@32e75460, 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.371s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[2]([Ljava.io.File;@56f47c60, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.375s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[3]([Ljava.io.File;@25523410, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.319s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[4]([Ljava.io.File;@57193882, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.322s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[5]([Ljava.io.File;@4c77dbca, 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.172s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[6]([Ljava.io.File;@1877fe88, 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
testMatePairFirstUnmapped 0.312s passed
testMatePairSecondUnmapped 0.305s passed
testNoReadGroupInRead 0.255s passed
testNonExistantReadGroupInRead 0.235s passed
testNullOpticalDuplicates 0.319s passed
testOpticalDuplicateClusterOneEndSamePositionOneCluster 0.328s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicatesWithinPixelDistance 0.310s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.320s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.319s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.309s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.301s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.325s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.308s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.307s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.316s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.321s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.304s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.301s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.318s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.308s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.322s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.326s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.313s passed
testOpticalDuplicateClusterSamePositionOneOpticalDuplicatesWithinPixelDistance 0.303s passed
testOpticalDuplicateClustersAddingSecondEndFirstSameCoordinate 0.306s passed
testOpticalDuplicateFinding 0.303s passed
testOpticalDuplicateFindingPxelDistance 0.314s passed
testOpticalDuplicatesAndPCRDuplicatesOrientationDifference 0.305s passed
testOpticalDuplicatesDifferentReadGroups 0.307s passed
testOpticalDuplicatesTheSameReadGroup 0.301s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.310s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.301s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.303s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.301s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.304s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.307s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.303s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.310s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.314s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.299s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.308s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.308s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.303s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.313s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.306s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.299s passed
testPathologicalOrderingAtTheSamePosition 0.302s passed
testReadSameStartPositionOrientationOverride 0.300s passed
testReadsHaveSameStartPositionButDifferentChromosomeNonEquivalence 0.313s passed
testSecondEndIsBeforeFirstInCoordinate 0.312s passed
testSingleMappedFragment 0.306s passed
testSingleMappedFragmentAndSingleMappedPair 0.310s passed
testSingleMappedFragmentAndTwoMappedPairs 0.301s passed
testSingleMappedPair 0.302s passed
testSingleUnmappedFragment 0.310s passed
testSingleUnmappedPair 0.300s passed
testStackOverFlowPairSetSwap 0.306s passed
testSupplementaryReadUnmappedMate 0.300s passed
testThreeGroupsOnDifferentChromosomesOfThreeMappedPairs 0.302s passed
testThreeMappedPairs 0.299s passed
testThreeMappedPairsWithMatchingSecondMate 0.304s passed
testTwoGroupsOnDifferentChromosomesOfThreeMappedPairs 0.309s passed
testTwoGroupsOnDifferentChromosomesOfTwoFragments 0.312s passed
testTwoGroupsOnDifferentChromosomesOfTwoMappedPairs 0.321s passed
testTwoMappedFragments 0.332s passed
testTwoMappedPairWithSamePosition 0.315s passed
testTwoMappedPairWithSamePositionDifferentStrands 0.317s passed
testTwoMappedPairWithSamePositionDifferentStrands2 0.293s passed
testTwoMappedPairs 0.310s passed
testTwoMappedPairsAndMappedSecondaryFragment 0.300s passed
testTwoMappedPairsAndTerminalUnmappedFragment 0.299s passed
testTwoMappedPairsAndTerminalUnmappedPair 0.303s passed
testTwoMappedPairsMatesSoftClipped 0.300s passed
testTwoMappedPairsWithOppositeOrientations 0.309s passed
testTwoMappedPairsWithOppositeOrientationsNumberTwo 0.293s passed
testTwoMappedPairsWithSoftClipping 0.302s passed
testTwoMappedPairsWithSoftClippingBoth 0.301s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnly 0.310s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnlyNoMateCigar 0.305s passed
testTwoMappedPairsWithSupplementaryReads[0](true, true, true) 0.305s passed
testTwoMappedPairsWithSupplementaryReads[1](true, false, true) 0.308s passed
testTwoMappedPairsWithSupplementaryReads[2](false, true, true) 0.303s passed
testTwoMappedPairsWithSupplementaryReads[3](true, true, false) 0.305s passed
testTwoMappedPairsWithSupplementaryReads[4](true, false, false) 0.302s passed
testTwoMappedPairsWithSupplementaryReads[5](false, true, false) 0.307s passed
testTwoUnmappedFragments 0.297s passed

Standard error

[June 2, 2025 at 2:35:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1054867456
[June 2, 2025 at 2:35:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1054867456
[June 2, 2025 at 2:35:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1054867456
[June 2, 2025 at 2:35:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
14:35:39.382 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:35:39.382 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5749ecb-SNAPSHOT
14:35:39.383 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:35:39.383 INFO  MarkDuplicatesSpark - Executing as root@7f71e7f19701 on Linux v6.11.0-1014-azure amd64
14:35:39.383 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:35:39.383 INFO  MarkDuplicatesSpark - Start Date/Time: June 2, 2025 at 2:35:39 PM GMT
14:35:39.383 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:35:39.383 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:35:39.383 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:35:39.383 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:35:39.383 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:35:39.383 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:35:39.383 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:35:39.383 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:35:39.383 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:35:39.383 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:35:39.383 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:35:39.384 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:35:39.384 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:35:39.384 INFO  MarkDuplicatesSpark - Initializing engine
14:35:39.384 INFO  MarkDuplicatesSpark - Done initializing engine
14:35:39.384 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:35:39.386 INFO  MemoryStore - Block broadcast_1337 stored as values in memory (estimated size 305.5 KiB, free 1914.1 MiB)
14:35:39.393 INFO  MemoryStore - Block broadcast_1337_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1914.0 MiB)
14:35:39.393 INFO  BlockManagerInfo - Added broadcast_1337_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.5 MiB)
14:35:39.394 INFO  SparkContext - Created broadcast 1337 from newAPIHadoopFile at PathSplitSource.java:96
14:35:39.414 INFO  MemoryStore - Block broadcast_1338 stored as values in memory (estimated size 305.5 KiB, free 1913.7 MiB)
14:35:39.421 INFO  MemoryStore - Block broadcast_1338_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1913.6 MiB)
14:35:39.421 INFO  BlockManagerInfo - Added broadcast_1338_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.4 MiB)
14:35:39.421 INFO  SparkContext - Created broadcast 1338 from newAPIHadoopFile at PathSplitSource.java:96
14:35:39.455 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:35:39.455 INFO  FileInputFormat - Total input files to process : 1
14:35:39.456 INFO  DAGScheduler - Registering RDD 3396 (mapToPair at SparkUtils.java:161) as input to shuffle 97
14:35:39.456 INFO  DAGScheduler - Got job 413 (collect at SparkUtils.java:205) with 1 output partitions
14:35:39.456 INFO  DAGScheduler - Final stage: ResultStage 721 (collect at SparkUtils.java:205)
14:35:39.456 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 720)
14:35:39.457 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 720)
14:35:39.457 INFO  DAGScheduler - Submitting ShuffleMapStage 720 (MapPartitionsRDD[3396] at mapToPair at SparkUtils.java:161), which has no missing parents
14:35:39.474 INFO  MemoryStore - Block broadcast_1339 stored as values in memory (estimated size 459.2 KiB, free 1913.2 MiB)
14:35:39.476 INFO  MemoryStore - Block broadcast_1339_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1913.0 MiB)
14:35:39.477 INFO  BlockManagerInfo - Added broadcast_1339_piece0 in memory on localhost:34931 (size: 201.4 KiB, free: 1919.2 MiB)
14:35:39.477 INFO  SparkContext - Created broadcast 1339 from broadcast at DAGScheduler.scala:1580
14:35:39.477 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))
14:35:39.478 INFO  TaskSchedulerImpl - Adding task set 720.0 with 1 tasks resource profile 0
14:35:39.478 INFO  TaskSetManager - Starting task 0.0 in stage 720.0 (TID 650) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9650 bytes) 
14:35:39.479 INFO  Executor - Running task 0.0 in stage 720.0 (TID 650)
14:35:39.508 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam:0+1507
14:35:39.513 INFO  Executor - Finished task 0.0 in stage 720.0 (TID 650). 1148 bytes result sent to driver
14:35:39.513 INFO  TaskSetManager - Finished task 0.0 in stage 720.0 (TID 650) in 35 ms on localhost (executor driver) (1/1)
14:35:39.513 INFO  TaskSchedulerImpl - Removed TaskSet 720.0, whose tasks have all completed, from pool 
14:35:39.513 INFO  DAGScheduler - ShuffleMapStage 720 (mapToPair at SparkUtils.java:161) finished in 0.056 s
14:35:39.513 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.514 INFO  DAGScheduler - running: HashSet()
14:35:39.514 INFO  DAGScheduler - waiting: HashSet(ResultStage 721)
14:35:39.514 INFO  DAGScheduler - failed: HashSet()
14:35:39.514 INFO  DAGScheduler - Submitting ResultStage 721 (MapPartitionsRDD[3399] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:35:39.515 INFO  MemoryStore - Block broadcast_1340 stored as values in memory (estimated size 7.4 KiB, free 1913.0 MiB)
14:35:39.515 INFO  MemoryStore - Block broadcast_1340_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1913.0 MiB)
14:35:39.516 INFO  BlockManagerInfo - Added broadcast_1340_piece0 in memory on localhost:34931 (size: 4.1 KiB, free: 1919.2 MiB)
14:35:39.516 INFO  SparkContext - Created broadcast 1340 from broadcast at DAGScheduler.scala:1580
14:35:39.516 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))
14:35:39.516 INFO  TaskSchedulerImpl - Adding task set 721.0 with 1 tasks resource profile 0
14:35:39.517 INFO  TaskSetManager - Starting task 0.0 in stage 721.0 (TID 651) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:35:39.517 INFO  Executor - Running task 0.0 in stage 721.0 (TID 651)
14:35:39.518 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
14:35:39.518 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.521 INFO  Executor - Finished task 0.0 in stage 721.0 (TID 651). 2238 bytes result sent to driver
14:35:39.521 INFO  TaskSetManager - Finished task 0.0 in stage 721.0 (TID 651) in 4 ms on localhost (executor driver) (1/1)
14:35:39.521 INFO  TaskSchedulerImpl - Removed TaskSet 721.0, whose tasks have all completed, from pool 
14:35:39.521 INFO  DAGScheduler - ResultStage 721 (collect at SparkUtils.java:205) finished in 0.007 s
14:35:39.521 INFO  DAGScheduler - Job 413 is finished. Cancelling potential speculative or zombie tasks for this job
14:35:39.521 INFO  TaskSchedulerImpl - Killing all running tasks in stage 721: Stage finished
14:35:39.522 INFO  DAGScheduler - Job 413 finished: collect at SparkUtils.java:205, took 0.066833 s
14:35:39.526 INFO  MemoryStore - Block broadcast_1341 stored as values in memory (estimated size 1632.0 B, free 1913.0 MiB)
14:35:39.527 INFO  MemoryStore - Block broadcast_1341_piece0 stored as bytes in memory (estimated size 145.0 B, free 1913.0 MiB)
14:35:39.527 INFO  BlockManagerInfo - Added broadcast_1341_piece0 in memory on localhost:34931 (size: 145.0 B, free: 1919.2 MiB)
14:35:39.527 INFO  SparkContext - Created broadcast 1341 from broadcast at MarkDuplicatesSparkUtils.java:126
14:35:39.527 INFO  MemoryStore - Block broadcast_1342 stored as values in memory (estimated size 304.0 B, free 1913.0 MiB)
14:35:39.528 INFO  MemoryStore - Block broadcast_1342_piece0 stored as bytes in memory (estimated size 37.0 B, free 1913.0 MiB)
14:35:39.528 INFO  BlockManagerInfo - Added broadcast_1342_piece0 in memory on localhost:34931 (size: 37.0 B, free: 1919.2 MiB)
14:35:39.528 INFO  SparkContext - Created broadcast 1342 from broadcast at MarkDuplicatesSparkUtils.java:127
14:35:39.543 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:35:39.543 INFO  DAGScheduler - Registering RDD 3408 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 100
14:35:39.544 INFO  DAGScheduler - Registering RDD 3412 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 99
14:35:39.544 INFO  DAGScheduler - Registering RDD 3416 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 98
14:35:39.544 INFO  DAGScheduler - Got job 414 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:35:39.544 INFO  DAGScheduler - Final stage: ResultStage 726 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:35:39.544 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 725)
14:35:39.544 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 725)
14:35:39.544 INFO  DAGScheduler - Submitting ShuffleMapStage 723 (MapPartitionsRDD[3408] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:35:39.545 INFO  MemoryStore - Block broadcast_1343 stored as values in memory (estimated size 24.2 KiB, free 1913.0 MiB)
14:35:39.546 INFO  MemoryStore - Block broadcast_1343_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1912.9 MiB)
14:35:39.546 INFO  BlockManagerInfo - Added broadcast_1343_piece0 in memory on localhost:34931 (size: 12.6 KiB, free: 1919.2 MiB)
14:35:39.546 INFO  SparkContext - Created broadcast 1343 from broadcast at DAGScheduler.scala:1580
14:35:39.546 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))
14:35:39.546 INFO  TaskSchedulerImpl - Adding task set 723.0 with 1 tasks resource profile 0
14:35:39.547 INFO  TaskSetManager - Starting task 0.0 in stage 723.0 (TID 652) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:35:39.548 INFO  Executor - Running task 0.0 in stage 723.0 (TID 652)
14:35:39.550 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
14:35:39.550 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.554 INFO  Executor - Finished task 0.0 in stage 723.0 (TID 652). 1922 bytes result sent to driver
14:35:39.554 INFO  TaskSetManager - Finished task 0.0 in stage 723.0 (TID 652) in 7 ms on localhost (executor driver) (1/1)
14:35:39.554 INFO  TaskSchedulerImpl - Removed TaskSet 723.0, whose tasks have all completed, from pool 
14:35:39.555 INFO  DAGScheduler - ShuffleMapStage 723 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.011 s
14:35:39.555 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.555 INFO  DAGScheduler - running: HashSet()
14:35:39.555 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 724, ShuffleMapStage 725, ResultStage 726)
14:35:39.555 INFO  DAGScheduler - failed: HashSet()
14:35:39.555 INFO  DAGScheduler - Submitting ShuffleMapStage 724 (MapPartitionsRDD[3412] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:35:39.556 INFO  MemoryStore - Block broadcast_1344 stored as values in memory (estimated size 28.3 KiB, free 1912.9 MiB)
14:35:39.557 INFO  MemoryStore - Block broadcast_1344_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1912.9 MiB)
14:35:39.557 INFO  BlockManagerInfo - Added broadcast_1344_piece0 in memory on localhost:34931 (size: 14.8 KiB, free: 1919.2 MiB)
14:35:39.557 INFO  SparkContext - Created broadcast 1344 from broadcast at DAGScheduler.scala:1580
14:35:39.557 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))
14:35:39.557 INFO  TaskSchedulerImpl - Adding task set 724.0 with 1 tasks resource profile 0
14:35:39.558 INFO  TaskSetManager - Starting task 0.0 in stage 724.0 (TID 653) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:35:39.558 INFO  Executor - Running task 0.0 in stage 724.0 (TID 653)
14:35:39.560 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
14:35:39.560 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.564 INFO  Executor - Finished task 0.0 in stage 724.0 (TID 653). 1922 bytes result sent to driver
14:35:39.565 INFO  TaskSetManager - Finished task 0.0 in stage 724.0 (TID 653) in 8 ms on localhost (executor driver) (1/1)
14:35:39.565 INFO  TaskSchedulerImpl - Removed TaskSet 724.0, whose tasks have all completed, from pool 
14:35:39.565 INFO  DAGScheduler - ShuffleMapStage 724 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.010 s
14:35:39.565 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.565 INFO  DAGScheduler - running: HashSet()
14:35:39.565 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 725, ResultStage 726)
14:35:39.565 INFO  DAGScheduler - failed: HashSet()
14:35:39.565 INFO  DAGScheduler - Submitting ShuffleMapStage 725 (MapPartitionsRDD[3416] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:35:39.566 INFO  MemoryStore - Block broadcast_1345 stored as values in memory (estimated size 19.0 KiB, free 1912.9 MiB)
14:35:39.567 INFO  MemoryStore - Block broadcast_1345_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1912.9 MiB)
14:35:39.567 INFO  BlockManagerInfo - Added broadcast_1345_piece0 in memory on localhost:34931 (size: 9.7 KiB, free: 1919.2 MiB)
14:35:39.567 INFO  SparkContext - Created broadcast 1345 from broadcast at DAGScheduler.scala:1580
14:35:39.568 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))
14:35:39.568 INFO  TaskSchedulerImpl - Adding task set 725.0 with 1 tasks resource profile 0
14:35:39.568 INFO  TaskSetManager - Starting task 0.0 in stage 725.0 (TID 654) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:35:39.568 INFO  Executor - Running task 0.0 in stage 725.0 (TID 654)
14:35:39.570 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
14:35:39.570 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.573 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
14:35:39.573 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.575 INFO  Executor - Finished task 0.0 in stage 725.0 (TID 654). 1922 bytes result sent to driver
14:35:39.575 INFO  TaskSetManager - Finished task 0.0 in stage 725.0 (TID 654) in 7 ms on localhost (executor driver) (1/1)
14:35:39.576 INFO  TaskSchedulerImpl - Removed TaskSet 725.0, whose tasks have all completed, from pool 
14:35:39.576 INFO  DAGScheduler - ShuffleMapStage 725 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.010 s
14:35:39.576 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.576 INFO  DAGScheduler - running: HashSet()
14:35:39.576 INFO  DAGScheduler - waiting: HashSet(ResultStage 726)
14:35:39.576 INFO  DAGScheduler - failed: HashSet()
14:35:39.576 INFO  DAGScheduler - Submitting ResultStage 726 (MapPartitionsRDD[3418] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:35:39.577 INFO  MemoryStore - Block broadcast_1346 stored as values in memory (estimated size 20.2 KiB, free 1912.9 MiB)
14:35:39.578 INFO  MemoryStore - Block broadcast_1346_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1912.8 MiB)
14:35:39.578 INFO  BlockManagerInfo - Added broadcast_1346_piece0 in memory on localhost:34931 (size: 10.6 KiB, free: 1919.2 MiB)
14:35:39.578 INFO  SparkContext - Created broadcast 1346 from broadcast at DAGScheduler.scala:1580
14:35:39.578 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))
14:35:39.578 INFO  TaskSchedulerImpl - Adding task set 726.0 with 1 tasks resource profile 0
14:35:39.579 INFO  TaskSetManager - Starting task 0.0 in stage 726.0 (TID 655) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:35:39.579 INFO  Executor - Running task 0.0 in stage 726.0 (TID 655)
14:35:39.581 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
14:35:39.581 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.584 INFO  Executor - Finished task 0.0 in stage 726.0 (TID 655). 1944 bytes result sent to driver
14:35:39.584 INFO  TaskSetManager - Finished task 0.0 in stage 726.0 (TID 655) in 5 ms on localhost (executor driver) (1/1)
14:35:39.584 INFO  TaskSchedulerImpl - Removed TaskSet 726.0, whose tasks have all completed, from pool 
14:35:39.585 INFO  DAGScheduler - ResultStage 726 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.009 s
14:35:39.585 INFO  DAGScheduler - Job 414 is finished. Cancelling potential speculative or zombie tasks for this job
14:35:39.585 INFO  TaskSchedulerImpl - Killing all running tasks in stage 726: Stage finished
14:35:39.585 INFO  DAGScheduler - Job 414 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.042017 s
14:35:39.599 INFO  MemoryStore - Block broadcast_1347 stored as values in memory (estimated size 20.3 KiB, free 1912.8 MiB)
14:35:39.600 INFO  MemoryStore - Block broadcast_1347_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1912.8 MiB)
14:35:39.600 INFO  BlockManagerInfo - Added broadcast_1347_piece0 in memory on localhost:34931 (size: 1850.0 B, free: 1919.2 MiB)
14:35:39.600 INFO  SparkContext - Created broadcast 1347 from broadcast at ReadsSparkSink.java:133
14:35:39.601 INFO  MemoryStore - Block broadcast_1348 stored as values in memory (estimated size 20.4 KiB, free 1912.8 MiB)
14:35:39.601 INFO  MemoryStore - Block broadcast_1348_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1912.8 MiB)
14:35:39.602 INFO  BlockManagerInfo - Added broadcast_1348_piece0 in memory on localhost:34931 (size: 1850.0 B, free: 1919.2 MiB)
14:35:39.602 INFO  SparkContext - Created broadcast 1348 from broadcast at BamSink.java:76
14:35:39.604 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:35:39.604 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:35:39.604 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:35:39.616 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:35:39.616 INFO  DAGScheduler - Registering RDD 3420 (mapToPair at SparkUtils.java:161) as input to shuffle 101
14:35:39.616 INFO  DAGScheduler - Got job 415 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:35:39.616 INFO  DAGScheduler - Final stage: ResultStage 731 (runJob at SparkHadoopWriter.scala:83)
14:35:39.616 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 730)
14:35:39.616 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 730)
14:35:39.617 INFO  DAGScheduler - Submitting ShuffleMapStage 730 (MapPartitionsRDD[3420] at mapToPair at SparkUtils.java:161), which has no missing parents
14:35:39.617 INFO  MemoryStore - Block broadcast_1349 stored as values in memory (estimated size 18.1 KiB, free 1912.8 MiB)
14:35:39.618 INFO  MemoryStore - Block broadcast_1349_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1912.8 MiB)
14:35:39.618 INFO  BlockManagerInfo - Added broadcast_1349_piece0 in memory on localhost:34931 (size: 9.5 KiB, free: 1919.2 MiB)
14:35:39.618 INFO  SparkContext - Created broadcast 1349 from broadcast at DAGScheduler.scala:1580
14:35:39.618 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))
14:35:39.618 INFO  TaskSchedulerImpl - Adding task set 730.0 with 1 tasks resource profile 0
14:35:39.619 INFO  TaskSetManager - Starting task 0.0 in stage 730.0 (TID 656) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:35:39.619 INFO  Executor - Running task 0.0 in stage 730.0 (TID 656)
14:35:39.621 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
14:35:39.621 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.623 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
14:35:39.624 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.625 INFO  Executor - Finished task 0.0 in stage 730.0 (TID 656). 1922 bytes result sent to driver
14:35:39.626 INFO  TaskSetManager - Finished task 0.0 in stage 730.0 (TID 656) in 7 ms on localhost (executor driver) (1/1)
14:35:39.626 INFO  TaskSchedulerImpl - Removed TaskSet 730.0, whose tasks have all completed, from pool 
14:35:39.626 INFO  DAGScheduler - ShuffleMapStage 730 (mapToPair at SparkUtils.java:161) finished in 0.009 s
14:35:39.626 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.626 INFO  DAGScheduler - running: HashSet()
14:35:39.626 INFO  DAGScheduler - waiting: HashSet(ResultStage 731)
14:35:39.626 INFO  DAGScheduler - failed: HashSet()
14:35:39.626 INFO  DAGScheduler - Submitting ResultStage 731 (MapPartitionsRDD[3425] at mapToPair at BamSink.java:91), which has no missing parents
14:35:39.633 INFO  MemoryStore - Block broadcast_1350 stored as values in memory (estimated size 163.3 KiB, free 1912.6 MiB)
14:35:39.634 INFO  MemoryStore - Block broadcast_1350_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1912.5 MiB)
14:35:39.634 INFO  BlockManagerInfo - Added broadcast_1350_piece0 in memory on localhost:34931 (size: 73.4 KiB, free: 1919.1 MiB)
14:35:39.634 INFO  SparkContext - Created broadcast 1350 from broadcast at DAGScheduler.scala:1580
14:35:39.634 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))
14:35:39.635 INFO  TaskSchedulerImpl - Adding task set 731.0 with 1 tasks resource profile 0
14:35:39.635 INFO  TaskSetManager - Starting task 0.0 in stage 731.0 (TID 657) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:35:39.635 INFO  Executor - Running task 0.0 in stage 731.0 (TID 657)
14:35:39.639 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
14:35:39.639 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.642 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:35:39.642 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:35:39.642 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:35:39.642 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:35:39.642 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:35:39.642 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:35:39.653 INFO  FileOutputCommitter - Saved output of task 'attempt_202506021435391291006412418689513_3425_r_000000_0' to file:/tmp/local15649932464249107734/markdups15473241083340556828.bam.parts/_temporary/0/task_202506021435391291006412418689513_3425_r_000000
14:35:39.653 INFO  SparkHadoopMapRedUtil - attempt_202506021435391291006412418689513_3425_r_000000_0: Committed. Elapsed time: 0 ms.
14:35:39.653 INFO  Executor - Finished task 0.0 in stage 731.0 (TID 657). 1858 bytes result sent to driver
14:35:39.653 INFO  TaskSetManager - Finished task 0.0 in stage 731.0 (TID 657) in 18 ms on localhost (executor driver) (1/1)
14:35:39.654 INFO  TaskSchedulerImpl - Removed TaskSet 731.0, whose tasks have all completed, from pool 
14:35:39.654 INFO  DAGScheduler - ResultStage 731 (runJob at SparkHadoopWriter.scala:83) finished in 0.027 s
14:35:39.654 INFO  DAGScheduler - Job 415 is finished. Cancelling potential speculative or zombie tasks for this job
14:35:39.654 INFO  TaskSchedulerImpl - Killing all running tasks in stage 731: Stage finished
14:35:39.654 INFO  DAGScheduler - Job 415 finished: runJob at SparkHadoopWriter.scala:83, took 0.038212 s
14:35:39.654 INFO  SparkHadoopWriter - Start to commit write Job job_202506021435391291006412418689513_3425.
14:35:39.657 INFO  SparkHadoopWriter - Write Job job_202506021435391291006412418689513_3425 committed. Elapsed time: 2 ms.
14:35:39.664 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local15649932464249107734/markdups15473241083340556828.bam
14:35:39.666 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local15649932464249107734/markdups15473241083340556828.bam done
14:35:39.666 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local15649932464249107734/markdups15473241083340556828.bam.parts/ to /tmp/local15649932464249107734/markdups15473241083340556828.bam.sbi
14:35:39.669 INFO  IndexFileMerger - Done merging .sbi files
14:35:39.669 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local15649932464249107734/markdups15473241083340556828.bam.parts/ to /tmp/local15649932464249107734/markdups15473241083340556828.bam.bai
14:35:39.672 INFO  IndexFileMerger - Done merging .bai files
14:35:39.672 INFO  MarkDuplicatesSpark - Shutting down engine
[June 2, 2025 at 2:35:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
14:35:39.689 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:35:39.689 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5749ecb-SNAPSHOT
14:35:39.689 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:35:39.689 INFO  MarkDuplicatesSpark - Executing as root@7f71e7f19701 on Linux v6.11.0-1014-azure amd64
14:35:39.689 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:35:39.689 INFO  MarkDuplicatesSpark - Start Date/Time: June 2, 2025 at 2:35:39 PM GMT
14:35:39.689 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:35:39.689 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:35:39.689 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:35:39.689 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:35:39.689 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:35:39.689 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:35:39.690 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:35:39.690 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:35:39.690 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:35:39.690 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:35:39.690 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:35:39.690 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:35:39.690 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:35:39.690 INFO  MarkDuplicatesSpark - Initializing engine
14:35:39.690 INFO  MarkDuplicatesSpark - Done initializing engine
14:35:39.690 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:35:39.692 INFO  MemoryStore - Block broadcast_1351 stored as values in memory (estimated size 305.5 KiB, free 1912.2 MiB)
14:35:39.699 INFO  MemoryStore - Block broadcast_1351_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1912.2 MiB)
14:35:39.699 INFO  BlockManagerInfo - Added broadcast_1351_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.0 MiB)
14:35:39.699 INFO  SparkContext - Created broadcast 1351 from newAPIHadoopFile at PathSplitSource.java:96
14:35:39.719 INFO  MemoryStore - Block broadcast_1352 stored as values in memory (estimated size 305.5 KiB, free 1911.9 MiB)
14:35:39.725 INFO  MemoryStore - Block broadcast_1352_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1911.8 MiB)
14:35:39.726 INFO  BlockManagerInfo - Added broadcast_1352_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.0 MiB)
14:35:39.726 INFO  SparkContext - Created broadcast 1352 from newAPIHadoopFile at PathSplitSource.java:96
14:35:39.758 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:35:39.758 INFO  FileInputFormat - Total input files to process : 1
14:35:39.759 INFO  DAGScheduler - Registering RDD 3439 (mapToPair at SparkUtils.java:161) as input to shuffle 102
14:35:39.759 INFO  DAGScheduler - Got job 416 (collect at SparkUtils.java:205) with 1 output partitions
14:35:39.759 INFO  DAGScheduler - Final stage: ResultStage 733 (collect at SparkUtils.java:205)
14:35:39.759 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 732)
14:35:39.759 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 732)
14:35:39.759 INFO  DAGScheduler - Submitting ShuffleMapStage 732 (MapPartitionsRDD[3439] at mapToPair at SparkUtils.java:161), which has no missing parents
14:35:39.776 INFO  MemoryStore - Block broadcast_1353 stored as values in memory (estimated size 459.2 KiB, free 1911.4 MiB)
14:35:39.779 INFO  MemoryStore - Block broadcast_1353_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1911.2 MiB)
14:35:39.779 INFO  BlockManagerInfo - Added broadcast_1353_piece0 in memory on localhost:34931 (size: 201.4 KiB, free: 1918.8 MiB)
14:35:39.779 INFO  SparkContext - Created broadcast 1353 from broadcast at DAGScheduler.scala:1580
14:35:39.779 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))
14:35:39.780 INFO  TaskSchedulerImpl - Adding task set 732.0 with 1 tasks resource profile 0
14:35:39.780 INFO  TaskSetManager - Starting task 0.0 in stage 732.0 (TID 658) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9651 bytes) 
14:35:39.780 INFO  Executor - Running task 0.0 in stage 732.0 (TID 658)
14:35:39.808 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam:0+1856
14:35:39.813 INFO  Executor - Finished task 0.0 in stage 732.0 (TID 658). 1148 bytes result sent to driver
14:35:39.814 INFO  TaskSetManager - Finished task 0.0 in stage 732.0 (TID 658) in 33 ms on localhost (executor driver) (1/1)
14:35:39.814 INFO  TaskSchedulerImpl - Removed TaskSet 732.0, whose tasks have all completed, from pool 
14:35:39.814 INFO  DAGScheduler - ShuffleMapStage 732 (mapToPair at SparkUtils.java:161) finished in 0.054 s
14:35:39.814 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.814 INFO  DAGScheduler - running: HashSet()
14:35:39.814 INFO  DAGScheduler - waiting: HashSet(ResultStage 733)
14:35:39.814 INFO  DAGScheduler - failed: HashSet()
14:35:39.814 INFO  DAGScheduler - Submitting ResultStage 733 (MapPartitionsRDD[3442] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:35:39.815 INFO  MemoryStore - Block broadcast_1354 stored as values in memory (estimated size 7.4 KiB, free 1911.2 MiB)
14:35:39.815 INFO  MemoryStore - Block broadcast_1354_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1911.2 MiB)
14:35:39.815 INFO  BlockManagerInfo - Added broadcast_1354_piece0 in memory on localhost:34931 (size: 4.1 KiB, free: 1918.8 MiB)
14:35:39.816 INFO  SparkContext - Created broadcast 1354 from broadcast at DAGScheduler.scala:1580
14:35:39.816 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))
14:35:39.816 INFO  TaskSchedulerImpl - Adding task set 733.0 with 1 tasks resource profile 0
14:35:39.816 INFO  TaskSetManager - Starting task 0.0 in stage 733.0 (TID 659) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:35:39.817 INFO  Executor - Running task 0.0 in stage 733.0 (TID 659)
14:35:39.818 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
14:35:39.818 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.819 INFO  Executor - Finished task 0.0 in stage 733.0 (TID 659). 2495 bytes result sent to driver
14:35:39.820 INFO  TaskSetManager - Finished task 0.0 in stage 733.0 (TID 659) in 4 ms on localhost (executor driver) (1/1)
14:35:39.820 INFO  TaskSchedulerImpl - Removed TaskSet 733.0, whose tasks have all completed, from pool 
14:35:39.820 INFO  DAGScheduler - ResultStage 733 (collect at SparkUtils.java:205) finished in 0.006 s
14:35:39.820 INFO  DAGScheduler - Job 416 is finished. Cancelling potential speculative or zombie tasks for this job
14:35:39.820 INFO  TaskSchedulerImpl - Killing all running tasks in stage 733: Stage finished
14:35:39.820 INFO  DAGScheduler - Job 416 finished: collect at SparkUtils.java:205, took 0.062246 s
14:35:39.824 INFO  MemoryStore - Block broadcast_1355 stored as values in memory (estimated size 1632.0 B, free 1911.2 MiB)
14:35:39.825 INFO  MemoryStore - Block broadcast_1355_piece0 stored as bytes in memory (estimated size 145.0 B, free 1911.2 MiB)
14:35:39.825 INFO  BlockManagerInfo - Added broadcast_1355_piece0 in memory on localhost:34931 (size: 145.0 B, free: 1918.8 MiB)
14:35:39.825 INFO  SparkContext - Created broadcast 1355 from broadcast at MarkDuplicatesSparkUtils.java:126
14:35:39.825 INFO  MemoryStore - Block broadcast_1356 stored as values in memory (estimated size 304.0 B, free 1911.2 MiB)
14:35:39.825 INFO  MemoryStore - Block broadcast_1356_piece0 stored as bytes in memory (estimated size 37.0 B, free 1911.2 MiB)
14:35:39.826 INFO  BlockManagerInfo - Added broadcast_1356_piece0 in memory on localhost:34931 (size: 37.0 B, free: 1918.8 MiB)
14:35:39.826 INFO  SparkContext - Created broadcast 1356 from broadcast at MarkDuplicatesSparkUtils.java:127
14:35:39.838 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:35:39.838 INFO  DAGScheduler - Registering RDD 3451 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 105
14:35:39.838 INFO  DAGScheduler - Registering RDD 3455 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 104
14:35:39.838 INFO  DAGScheduler - Registering RDD 3459 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 103
14:35:39.839 INFO  DAGScheduler - Got job 417 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:35:39.839 INFO  DAGScheduler - Final stage: ResultStage 738 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:35:39.839 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 737)
14:35:39.839 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 737)
14:35:39.839 INFO  DAGScheduler - Submitting ShuffleMapStage 735 (MapPartitionsRDD[3451] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:35:39.840 INFO  MemoryStore - Block broadcast_1357 stored as values in memory (estimated size 24.2 KiB, free 1911.1 MiB)
14:35:39.841 INFO  MemoryStore - Block broadcast_1357_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1911.1 MiB)
14:35:39.841 INFO  BlockManagerInfo - Added broadcast_1357_piece0 in memory on localhost:34931 (size: 12.6 KiB, free: 1918.8 MiB)
14:35:39.841 INFO  SparkContext - Created broadcast 1357 from broadcast at DAGScheduler.scala:1580
14:35:39.841 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))
14:35:39.841 INFO  TaskSchedulerImpl - Adding task set 735.0 with 1 tasks resource profile 0
14:35:39.842 INFO  TaskSetManager - Starting task 0.0 in stage 735.0 (TID 660) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:35:39.842 INFO  Executor - Running task 0.0 in stage 735.0 (TID 660)
14:35:39.844 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
14:35:39.844 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.847 INFO  Executor - Finished task 0.0 in stage 735.0 (TID 660). 1922 bytes result sent to driver
14:35:39.847 INFO  TaskSetManager - Finished task 0.0 in stage 735.0 (TID 660) in 5 ms on localhost (executor driver) (1/1)
14:35:39.847 INFO  TaskSchedulerImpl - Removed TaskSet 735.0, whose tasks have all completed, from pool 
14:35:39.847 INFO  DAGScheduler - ShuffleMapStage 735 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
14:35:39.848 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.848 INFO  DAGScheduler - running: HashSet()
14:35:39.848 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 736, ShuffleMapStage 737, ResultStage 738)
14:35:39.848 INFO  DAGScheduler - failed: HashSet()
14:35:39.848 INFO  DAGScheduler - Submitting ShuffleMapStage 736 (MapPartitionsRDD[3455] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:35:39.849 INFO  MemoryStore - Block broadcast_1358 stored as values in memory (estimated size 28.3 KiB, free 1911.1 MiB)
14:35:39.850 INFO  MemoryStore - Block broadcast_1358_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1911.1 MiB)
14:35:39.850 INFO  BlockManagerInfo - Added broadcast_1358_piece0 in memory on localhost:34931 (size: 14.8 KiB, free: 1918.7 MiB)
14:35:39.850 INFO  SparkContext - Created broadcast 1358 from broadcast at DAGScheduler.scala:1580
14:35:39.850 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))
14:35:39.850 INFO  TaskSchedulerImpl - Adding task set 736.0 with 1 tasks resource profile 0
14:35:39.851 INFO  TaskSetManager - Starting task 0.0 in stage 736.0 (TID 661) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:35:39.851 INFO  Executor - Running task 0.0 in stage 736.0 (TID 661)
14:35:39.852 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
14:35:39.853 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.856 INFO  Executor - Finished task 0.0 in stage 736.0 (TID 661). 1922 bytes result sent to driver
14:35:39.857 INFO  TaskSetManager - Finished task 0.0 in stage 736.0 (TID 661) in 6 ms on localhost (executor driver) (1/1)
14:35:39.857 INFO  TaskSchedulerImpl - Removed TaskSet 736.0, whose tasks have all completed, from pool 
14:35:39.857 INFO  DAGScheduler - ShuffleMapStage 736 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
14:35:39.857 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.857 INFO  DAGScheduler - running: HashSet()
14:35:39.857 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 737, ResultStage 738)
14:35:39.857 INFO  DAGScheduler - failed: HashSet()
14:35:39.857 INFO  DAGScheduler - Submitting ShuffleMapStage 737 (MapPartitionsRDD[3459] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:35:39.858 INFO  MemoryStore - Block broadcast_1359 stored as values in memory (estimated size 19.0 KiB, free 1911.1 MiB)
14:35:39.858 INFO  MemoryStore - Block broadcast_1359_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1911.1 MiB)
14:35:39.858 INFO  BlockManagerInfo - Added broadcast_1359_piece0 in memory on localhost:34931 (size: 9.7 KiB, free: 1918.7 MiB)
14:35:39.859 INFO  SparkContext - Created broadcast 1359 from broadcast at DAGScheduler.scala:1580
14:35:39.859 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))
14:35:39.859 INFO  TaskSchedulerImpl - Adding task set 737.0 with 1 tasks resource profile 0
14:35:39.859 INFO  TaskSetManager - Starting task 0.0 in stage 737.0 (TID 662) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:35:39.860 INFO  Executor - Running task 0.0 in stage 737.0 (TID 662)
14:35:39.861 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
14:35:39.861 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.864 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
14:35:39.864 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.865 INFO  Executor - Finished task 0.0 in stage 737.0 (TID 662). 1922 bytes result sent to driver
14:35:39.865 INFO  TaskSetManager - Finished task 0.0 in stage 737.0 (TID 662) in 6 ms on localhost (executor driver) (1/1)
14:35:39.865 INFO  TaskSchedulerImpl - Removed TaskSet 737.0, whose tasks have all completed, from pool 
14:35:39.866 INFO  DAGScheduler - ShuffleMapStage 737 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.009 s
14:35:39.866 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.866 INFO  DAGScheduler - running: HashSet()
14:35:39.866 INFO  DAGScheduler - waiting: HashSet(ResultStage 738)
14:35:39.866 INFO  DAGScheduler - failed: HashSet()
14:35:39.866 INFO  DAGScheduler - Submitting ResultStage 738 (MapPartitionsRDD[3461] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:35:39.867 INFO  MemoryStore - Block broadcast_1360 stored as values in memory (estimated size 20.2 KiB, free 1911.0 MiB)
14:35:39.867 INFO  MemoryStore - Block broadcast_1360_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1911.0 MiB)
14:35:39.867 INFO  BlockManagerInfo - Added broadcast_1360_piece0 in memory on localhost:34931 (size: 10.6 KiB, free: 1918.7 MiB)
14:35:39.868 INFO  SparkContext - Created broadcast 1360 from broadcast at DAGScheduler.scala:1580
14:35:39.868 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))
14:35:39.868 INFO  TaskSchedulerImpl - Adding task set 738.0 with 1 tasks resource profile 0
14:35:39.868 INFO  TaskSetManager - Starting task 0.0 in stage 738.0 (TID 663) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:35:39.868 INFO  Executor - Running task 0.0 in stage 738.0 (TID 663)
14:35:39.870 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
14:35:39.870 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.872 INFO  Executor - Finished task 0.0 in stage 738.0 (TID 663). 2053 bytes result sent to driver
14:35:39.873 INFO  TaskSetManager - Finished task 0.0 in stage 738.0 (TID 663) in 5 ms on localhost (executor driver) (1/1)
14:35:39.873 INFO  TaskSchedulerImpl - Removed TaskSet 738.0, whose tasks have all completed, from pool 
14:35:39.873 INFO  DAGScheduler - ResultStage 738 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.007 s
14:35:39.873 INFO  DAGScheduler - Job 417 is finished. Cancelling potential speculative or zombie tasks for this job
14:35:39.873 INFO  TaskSchedulerImpl - Killing all running tasks in stage 738: Stage finished
14:35:39.873 INFO  DAGScheduler - Job 417 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.035436 s
14:35:39.883 INFO  MemoryStore - Block broadcast_1361 stored as values in memory (estimated size 20.3 KiB, free 1911.0 MiB)
14:35:39.884 INFO  MemoryStore - Block broadcast_1361_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1911.0 MiB)
14:35:39.884 INFO  BlockManagerInfo - Added broadcast_1361_piece0 in memory on localhost:34931 (size: 1850.0 B, free: 1918.7 MiB)
14:35:39.884 INFO  SparkContext - Created broadcast 1361 from broadcast at ReadsSparkSink.java:133
14:35:39.885 INFO  MemoryStore - Block broadcast_1362 stored as values in memory (estimated size 20.4 KiB, free 1911.0 MiB)
14:35:39.890 INFO  MemoryStore - Block broadcast_1362_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1911.0 MiB)
14:35:39.891 INFO  BlockManagerInfo - Removed broadcast_1357_piece0 on localhost:34931 in memory (size: 12.6 KiB, free: 1918.7 MiB)
14:35:39.891 INFO  BlockManagerInfo - Added broadcast_1362_piece0 in memory on localhost:34931 (size: 1850.0 B, free: 1918.7 MiB)
14:35:39.891 INFO  SparkContext - Created broadcast 1362 from broadcast at BamSink.java:76
14:35:39.891 INFO  BlockManagerInfo - Removed broadcast_1358_piece0 on localhost:34931 in memory (size: 14.8 KiB, free: 1918.7 MiB)
14:35:39.892 INFO  BlockManagerInfo - Removed broadcast_1346_piece0 on localhost:34931 in memory (size: 10.6 KiB, free: 1918.8 MiB)
14:35:39.892 INFO  BlockManagerInfo - Removed broadcast_1338_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1918.8 MiB)
14:35:39.892 INFO  BlockManagerInfo - Removed broadcast_1345_piece0 on localhost:34931 in memory (size: 9.7 KiB, free: 1918.8 MiB)
14:35:39.893 INFO  BlockManagerInfo - Removed broadcast_1360_piece0 on localhost:34931 in memory (size: 10.6 KiB, free: 1918.8 MiB)
14:35:39.893 INFO  BlockManagerInfo - Removed broadcast_1347_piece0 on localhost:34931 in memory (size: 1850.0 B, free: 1918.8 MiB)
14:35:39.893 INFO  BlockManagerInfo - Removed broadcast_1351_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1918.9 MiB)
14:35:39.894 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:35:39.894 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:35:39.894 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:35:39.894 INFO  BlockManagerInfo - Removed broadcast_1353_piece0 on localhost:34931 in memory (size: 201.4 KiB, free: 1919.1 MiB)
14:35:39.894 INFO  BlockManagerInfo - Removed broadcast_1343_piece0 on localhost:34931 in memory (size: 12.6 KiB, free: 1919.1 MiB)
14:35:39.895 INFO  BlockManagerInfo - Removed broadcast_1340_piece0 on localhost:34931 in memory (size: 4.1 KiB, free: 1919.1 MiB)
14:35:39.895 INFO  BlockManagerInfo - Removed broadcast_1359_piece0 on localhost:34931 in memory (size: 9.7 KiB, free: 1919.1 MiB)
14:35:39.895 INFO  BlockManagerInfo - Removed broadcast_1337_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1919.2 MiB)
14:35:39.896 INFO  BlockManagerInfo - Removed broadcast_1354_piece0 on localhost:34931 in memory (size: 4.1 KiB, free: 1919.2 MiB)
14:35:39.896 INFO  BlockManagerInfo - Removed broadcast_1344_piece0 on localhost:34931 in memory (size: 14.8 KiB, free: 1919.2 MiB)
14:35:39.897 INFO  BlockManagerInfo - Removed broadcast_1341_piece0 on localhost:34931 in memory (size: 145.0 B, free: 1919.2 MiB)
14:35:39.897 INFO  BlockManagerInfo - Removed broadcast_1339_piece0 on localhost:34931 in memory (size: 201.4 KiB, free: 1919.4 MiB)
14:35:39.897 INFO  BlockManagerInfo - Removed broadcast_1349_piece0 on localhost:34931 in memory (size: 9.5 KiB, free: 1919.4 MiB)
14:35:39.898 INFO  BlockManagerInfo - Removed broadcast_1350_piece0 on localhost:34931 in memory (size: 73.4 KiB, free: 1919.5 MiB)
14:35:39.898 INFO  BlockManagerInfo - Removed broadcast_1342_piece0 on localhost:34931 in memory (size: 37.0 B, free: 1919.5 MiB)
14:35:39.899 INFO  BlockManagerInfo - Removed broadcast_1348_piece0 on localhost:34931 in memory (size: 1850.0 B, free: 1919.5 MiB)
14:35:39.907 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:35:39.907 INFO  DAGScheduler - Registering RDD 3463 (mapToPair at SparkUtils.java:161) as input to shuffle 106
14:35:39.907 INFO  DAGScheduler - Got job 418 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:35:39.907 INFO  DAGScheduler - Final stage: ResultStage 743 (runJob at SparkHadoopWriter.scala:83)
14:35:39.907 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 742)
14:35:39.907 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 742)
14:35:39.908 INFO  DAGScheduler - Submitting ShuffleMapStage 742 (MapPartitionsRDD[3463] at mapToPair at SparkUtils.java:161), which has no missing parents
14:35:39.908 INFO  MemoryStore - Block broadcast_1363 stored as values in memory (estimated size 18.1 KiB, free 1913.9 MiB)
14:35:39.909 INFO  MemoryStore - Block broadcast_1363_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1913.9 MiB)
14:35:39.909 INFO  BlockManagerInfo - Added broadcast_1363_piece0 in memory on localhost:34931 (size: 9.5 KiB, free: 1919.5 MiB)
14:35:39.909 INFO  SparkContext - Created broadcast 1363 from broadcast at DAGScheduler.scala:1580
14:35:39.909 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))
14:35:39.910 INFO  TaskSchedulerImpl - Adding task set 742.0 with 1 tasks resource profile 0
14:35:39.910 INFO  TaskSetManager - Starting task 0.0 in stage 742.0 (TID 664) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:35:39.910 INFO  Executor - Running task 0.0 in stage 742.0 (TID 664)
14:35:39.912 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
14:35:39.912 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.914 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
14:35:39.914 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.916 INFO  Executor - Finished task 0.0 in stage 742.0 (TID 664). 1922 bytes result sent to driver
14:35:39.916 INFO  TaskSetManager - Finished task 0.0 in stage 742.0 (TID 664) in 6 ms on localhost (executor driver) (1/1)
14:35:39.916 INFO  TaskSchedulerImpl - Removed TaskSet 742.0, whose tasks have all completed, from pool 
14:35:39.916 INFO  DAGScheduler - ShuffleMapStage 742 (mapToPair at SparkUtils.java:161) finished in 0.008 s
14:35:39.916 INFO  DAGScheduler - looking for newly runnable stages
14:35:39.916 INFO  DAGScheduler - running: HashSet()
14:35:39.916 INFO  DAGScheduler - waiting: HashSet(ResultStage 743)
14:35:39.916 INFO  DAGScheduler - failed: HashSet()
14:35:39.916 INFO  DAGScheduler - Submitting ResultStage 743 (MapPartitionsRDD[3468] at mapToPair at BamSink.java:91), which has no missing parents
14:35:39.923 INFO  MemoryStore - Block broadcast_1364 stored as values in memory (estimated size 163.3 KiB, free 1913.8 MiB)
14:35:39.924 INFO  MemoryStore - Block broadcast_1364_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1913.7 MiB)
14:35:39.924 INFO  BlockManagerInfo - Added broadcast_1364_piece0 in memory on localhost:34931 (size: 73.4 KiB, free: 1919.4 MiB)
14:35:39.924 INFO  SparkContext - Created broadcast 1364 from broadcast at DAGScheduler.scala:1580
14:35:39.924 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))
14:35:39.925 INFO  TaskSchedulerImpl - Adding task set 743.0 with 1 tasks resource profile 0
14:35:39.925 INFO  TaskSetManager - Starting task 0.0 in stage 743.0 (TID 665) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:35:39.925 INFO  Executor - Running task 0.0 in stage 743.0 (TID 665)
14:35:39.928 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
14:35:39.929 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:35:39.931 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:35:39.931 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:35:39.931 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:35:39.931 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:35:39.931 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:35:39.931 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:35:39.942 INFO  FileOutputCommitter - Saved output of task 'attempt_202506021435394214669296610921251_3468_r_000000_0' to file:/tmp/local15649932464249107734/markdups1001868606228321345.bam.parts/_temporary/0/task_202506021435394214669296610921251_3468_r_000000
14:35:39.942 INFO  SparkHadoopMapRedUtil - attempt_202506021435394214669296610921251_3468_r_000000_0: Committed. Elapsed time: 0 ms.
14:35:39.942 INFO  Executor - Finished task 0.0 in stage 743.0 (TID 665). 1858 bytes result sent to driver
14:35:39.943 INFO  TaskSetManager - Finished task 0.0 in stage 743.0 (TID 665) in 18 ms on localhost (executor driver) (1/1)
14:35:39.943 INFO  TaskSchedulerImpl - Removed TaskSet 743.0, whose tasks have all completed, from pool 
14:35:39.943 INFO  DAGScheduler - ResultStage 743 (runJob at SparkHadoopWriter.scala:83) finished in 0.026 s
14:35:39.943 INFO  DAGScheduler - Job 418 is finished. Cancelling potential speculative or zombie tasks for this job
14:35:39.943 INFO  TaskSchedulerImpl - Killing all running tasks in stage 743: Stage finished
14:35:39.943 INFO  DAGScheduler - Job 418 finished: runJob at SparkHadoopWriter.scala:83, took 0.036375 s
14:35:39.943 INFO  SparkHadoopWriter - Start to commit write Job job_202506021435394214669296610921251_3468.
14:35:39.946 INFO  SparkHadoopWriter - Write Job job_202506021435394214669296610921251_3468 committed. Elapsed time: 3 ms.
14:35:39.952 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local15649932464249107734/markdups1001868606228321345.bam
14:35:39.955 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local15649932464249107734/markdups1001868606228321345.bam done
14:35:39.955 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local15649932464249107734/markdups1001868606228321345.bam.parts/ to /tmp/local15649932464249107734/markdups1001868606228321345.bam.sbi
14:35:39.958 INFO  IndexFileMerger - Done merging .sbi files
14:35:39.958 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local15649932464249107734/markdups1001868606228321345.bam.parts/ to /tmp/local15649932464249107734/markdups1001868606228321345.bam.bai
14:35:39.961 INFO  IndexFileMerger - Done merging .bai files
14:35:39.961 INFO  MarkDuplicatesSpark - Shutting down engine
[June 2, 2025 at 2:35:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:51 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:53 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:53 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:35:59 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:04 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
14:36:05.032 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.032 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5749ecb-SNAPSHOT
14:36:05.032 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:36:05.032 INFO  MarkDuplicatesSpark - Executing as root@7f71e7f19701 on Linux v6.11.0-1014-azure amd64
14:36:05.032 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:36:05.032 INFO  MarkDuplicatesSpark - Start Date/Time: June 2, 2025 at 2:36:05 PM GMT
14:36:05.032 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.032 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.032 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:36:05.032 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:36:05.032 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:36:05.032 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:36:05.032 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:36:05.032 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:36:05.032 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:36:05.033 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:36:05.033 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:36:05.033 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:36:05.033 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:36:05.033 INFO  MarkDuplicatesSpark - Initializing engine
14:36:05.033 INFO  MarkDuplicatesSpark - Done initializing engine
14:36:05.033 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:36:05.035 INFO  MemoryStore - Block broadcast_1941 stored as values in memory (estimated size 305.5 KiB, free 1912.3 MiB)
14:36:05.042 INFO  MemoryStore - Block broadcast_1941_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1912.2 MiB)
14:36:05.042 INFO  BlockManagerInfo - Added broadcast_1941_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.0 MiB)
14:36:05.042 INFO  SparkContext - Created broadcast 1941 from newAPIHadoopFile at PathSplitSource.java:96
14:36:05.063 INFO  MemoryStore - Block broadcast_1942 stored as values in memory (estimated size 305.5 KiB, free 1911.9 MiB)
14:36:05.069 INFO  MemoryStore - Block broadcast_1942_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1911.9 MiB)
14:36:05.070 INFO  BlockManagerInfo - Added broadcast_1942_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.0 MiB)
14:36:05.070 INFO  SparkContext - Created broadcast 1942 from newAPIHadoopFile at PathSplitSource.java:96
14:36:05.102 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:36:05.102 INFO  FileInputFormat - Total input files to process : 1
14:36:05.103 INFO  DAGScheduler - Registering RDD 5360 (mapToPair at SparkUtils.java:161) as input to shuffle 297
14:36:05.103 INFO  DAGScheduler - Got job 549 (collect at SparkUtils.java:205) with 1 output partitions
14:36:05.103 INFO  DAGScheduler - Final stage: ResultStage 1205 (collect at SparkUtils.java:205)
14:36:05.103 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1204)
14:36:05.103 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1204)
14:36:05.103 INFO  DAGScheduler - Submitting ShuffleMapStage 1204 (MapPartitionsRDD[5360] at mapToPair at SparkUtils.java:161), which has no missing parents
14:36:05.120 INFO  MemoryStore - Block broadcast_1943 stored as values in memory (estimated size 492.6 KiB, free 1911.4 MiB)
14:36:05.123 INFO  MemoryStore - Block broadcast_1943_piece0 stored as bytes in memory (estimated size 208.9 KiB, free 1911.2 MiB)
14:36:05.123 INFO  BlockManagerInfo - Added broadcast_1943_piece0 in memory on localhost:34931 (size: 208.9 KiB, free: 1918.8 MiB)
14:36:05.123 INFO  SparkContext - Created broadcast 1943 from broadcast at DAGScheduler.scala:1580
14:36:05.123 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))
14:36:05.123 INFO  TaskSchedulerImpl - Adding task set 1204.0 with 1 tasks resource profile 0
14:36:05.124 INFO  TaskSetManager - Starting task 0.0 in stage 1204.0 (TID 1036) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9674 bytes) 
14:36:05.124 INFO  Executor - Running task 0.0 in stage 1204.0 (TID 1036)
14:36:05.152 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam:0+13412
14:36:05.158 INFO  Executor - Finished task 0.0 in stage 1204.0 (TID 1036). 1148 bytes result sent to driver
14:36:05.158 INFO  TaskSetManager - Finished task 0.0 in stage 1204.0 (TID 1036) in 35 ms on localhost (executor driver) (1/1)
14:36:05.158 INFO  TaskSchedulerImpl - Removed TaskSet 1204.0, whose tasks have all completed, from pool 
14:36:05.158 INFO  DAGScheduler - ShuffleMapStage 1204 (mapToPair at SparkUtils.java:161) finished in 0.055 s
14:36:05.158 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.158 INFO  DAGScheduler - running: HashSet()
14:36:05.158 INFO  DAGScheduler - waiting: HashSet(ResultStage 1205)
14:36:05.158 INFO  DAGScheduler - failed: HashSet()
14:36:05.158 INFO  DAGScheduler - Submitting ResultStage 1205 (MapPartitionsRDD[5363] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:36:05.159 INFO  MemoryStore - Block broadcast_1944 stored as values in memory (estimated size 7.4 KiB, free 1911.2 MiB)
14:36:05.159 INFO  MemoryStore - Block broadcast_1944_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1911.2 MiB)
14:36:05.159 INFO  BlockManagerInfo - Added broadcast_1944_piece0 in memory on localhost:34931 (size: 4.1 KiB, free: 1918.8 MiB)
14:36:05.160 INFO  SparkContext - Created broadcast 1944 from broadcast at DAGScheduler.scala:1580
14:36:05.160 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))
14:36:05.160 INFO  TaskSchedulerImpl - Adding task set 1205.0 with 1 tasks resource profile 0
14:36:05.160 INFO  TaskSetManager - Starting task 0.0 in stage 1205.0 (TID 1037) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.160 INFO  Executor - Running task 0.0 in stage 1205.0 (TID 1037)
14:36:05.161 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
14:36:05.161 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.164 INFO  Executor - Finished task 0.0 in stage 1205.0 (TID 1037). 2329 bytes result sent to driver
14:36:05.164 INFO  TaskSetManager - Finished task 0.0 in stage 1205.0 (TID 1037) in 4 ms on localhost (executor driver) (1/1)
14:36:05.164 INFO  TaskSchedulerImpl - Removed TaskSet 1205.0, whose tasks have all completed, from pool 
14:36:05.164 INFO  DAGScheduler - ResultStage 1205 (collect at SparkUtils.java:205) finished in 0.005 s
14:36:05.165 INFO  DAGScheduler - Job 549 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.165 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1205: Stage finished
14:36:05.165 INFO  DAGScheduler - Job 549 finished: collect at SparkUtils.java:205, took 0.062746 s
14:36:05.169 INFO  MemoryStore - Block broadcast_1945 stored as values in memory (estimated size 7.8 KiB, free 1911.2 MiB)
14:36:05.173 INFO  MemoryStore - Block broadcast_1945_piece0 stored as bytes in memory (estimated size 540.0 B, free 1911.2 MiB)
14:36:05.173 INFO  BlockManagerInfo - Added broadcast_1945_piece0 in memory on localhost:34931 (size: 540.0 B, free: 1918.8 MiB)
14:36:05.173 INFO  SparkContext - Created broadcast 1945 from broadcast at MarkDuplicatesSparkUtils.java:126
14:36:05.174 INFO  MemoryStore - Block broadcast_1946 stored as values in memory (estimated size 2.6 KiB, free 1911.2 MiB)
14:36:05.174 INFO  BlockManagerInfo - Removed broadcast_1930_piece0 on localhost:34931 in memory (size: 200.3 KiB, free: 1919.0 MiB)
14:36:05.174 INFO  MemoryStore - Block broadcast_1946_piece0 stored as bytes in memory (estimated size 209.0 B, free 1911.8 MiB)
14:36:05.174 INFO  BlockManagerInfo - Added broadcast_1946_piece0 in memory on localhost:34931 (size: 209.0 B, free: 1919.0 MiB)
14:36:05.175 INFO  BlockManagerInfo - Removed broadcast_1939_piece0 on localhost:34931 in memory (size: 8.0 KiB, free: 1919.0 MiB)
14:36:05.175 INFO  SparkContext - Created broadcast 1946 from broadcast at MarkDuplicatesSparkUtils.java:127
14:36:05.175 INFO  BlockManagerInfo - Removed broadcast_1937_piece0 on localhost:34931 in memory (size: 9.1 KiB, free: 1919.0 MiB)
14:36:05.175 INFO  BlockManagerInfo - Removed broadcast_1933_piece0 on localhost:34931 in memory (size: 31.0 B, free: 1919.0 MiB)
14:36:05.176 INFO  BlockManagerInfo - Removed broadcast_1931_piece0 on localhost:34931 in memory (size: 4.1 KiB, free: 1919.0 MiB)
14:36:05.177 INFO  BlockManagerInfo - Removed broadcast_1940_piece0 on localhost:34931 in memory (size: 71.6 KiB, free: 1919.1 MiB)
14:36:05.177 INFO  BlockManagerInfo - Removed broadcast_1938_piece0 on localhost:34931 in memory (size: 663.0 B, free: 1919.1 MiB)
14:36:05.178 INFO  BlockManagerInfo - Removed broadcast_1935_piece0 on localhost:34931 in memory (size: 13.2 KiB, free: 1919.1 MiB)
14:36:05.178 INFO  BlockManagerInfo - Removed broadcast_1934_piece0 on localhost:34931 in memory (size: 11.2 KiB, free: 1919.1 MiB)
14:36:05.178 INFO  BlockManagerInfo - Removed broadcast_1944_piece0 on localhost:34931 in memory (size: 4.1 KiB, free: 1919.1 MiB)
14:36:05.179 INFO  BlockManagerInfo - Removed broadcast_1936_piece0 on localhost:34931 in memory (size: 8.5 KiB, free: 1919.1 MiB)
14:36:05.179 INFO  BlockManagerInfo - Removed broadcast_1929_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1919.2 MiB)
14:36:05.180 INFO  BlockManagerInfo - Removed broadcast_1928_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1919.2 MiB)
14:36:05.180 INFO  BlockManagerInfo - Removed broadcast_1941_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1919.3 MiB)
14:36:05.180 INFO  BlockManagerInfo - Removed broadcast_1943_piece0 on localhost:34931 in memory (size: 208.9 KiB, free: 1919.5 MiB)
14:36:05.181 INFO  BlockManagerInfo - Removed broadcast_1932_piece0 on localhost:34931 in memory (size: 19.0 B, free: 1919.5 MiB)
14:36:05.190 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:36:05.191 INFO  DAGScheduler - Registering RDD 5372 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 300
14:36:05.191 INFO  DAGScheduler - Registering RDD 5376 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 299
14:36:05.191 INFO  DAGScheduler - Registering RDD 5380 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 298
14:36:05.191 INFO  DAGScheduler - Got job 550 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:36:05.191 INFO  DAGScheduler - Final stage: ResultStage 1210 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:36:05.191 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1209)
14:36:05.191 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1209)
14:36:05.191 INFO  DAGScheduler - Submitting ShuffleMapStage 1207 (MapPartitionsRDD[5372] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:36:05.192 INFO  MemoryStore - Block broadcast_1947 stored as values in memory (estimated size 57.6 KiB, free 1913.9 MiB)
14:36:05.193 INFO  MemoryStore - Block broadcast_1947_piece0 stored as bytes in memory (estimated size 19.8 KiB, free 1913.9 MiB)
14:36:05.193 INFO  BlockManagerInfo - Added broadcast_1947_piece0 in memory on localhost:34931 (size: 19.8 KiB, free: 1919.5 MiB)
14:36:05.193 INFO  SparkContext - Created broadcast 1947 from broadcast at DAGScheduler.scala:1580
14:36:05.193 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))
14:36:05.193 INFO  TaskSchedulerImpl - Adding task set 1207.0 with 1 tasks resource profile 0
14:36:05.194 INFO  TaskSetManager - Starting task 0.0 in stage 1207.0 (TID 1038) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:36:05.194 INFO  Executor - Running task 0.0 in stage 1207.0 (TID 1038)
14:36:05.196 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
14:36:05.196 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.200 INFO  Executor - Finished task 0.0 in stage 1207.0 (TID 1038). 1922 bytes result sent to driver
14:36:05.200 INFO  TaskSetManager - Finished task 0.0 in stage 1207.0 (TID 1038) in 6 ms on localhost (executor driver) (1/1)
14:36:05.200 INFO  TaskSchedulerImpl - Removed TaskSet 1207.0, whose tasks have all completed, from pool 
14:36:05.200 INFO  DAGScheduler - ShuffleMapStage 1207 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.009 s
14:36:05.200 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.200 INFO  DAGScheduler - running: HashSet()
14:36:05.200 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1208, ShuffleMapStage 1209, ResultStage 1210)
14:36:05.200 INFO  DAGScheduler - failed: HashSet()
14:36:05.201 INFO  DAGScheduler - Submitting ShuffleMapStage 1208 (MapPartitionsRDD[5376] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:36:05.202 INFO  MemoryStore - Block broadcast_1948 stored as values in memory (estimated size 61.7 KiB, free 1913.8 MiB)
14:36:05.202 INFO  MemoryStore - Block broadcast_1948_piece0 stored as bytes in memory (estimated size 22.0 KiB, free 1913.8 MiB)
14:36:05.202 INFO  BlockManagerInfo - Added broadcast_1948_piece0 in memory on localhost:34931 (size: 22.0 KiB, free: 1919.4 MiB)
14:36:05.202 INFO  SparkContext - Created broadcast 1948 from broadcast at DAGScheduler.scala:1580
14:36:05.203 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))
14:36:05.203 INFO  TaskSchedulerImpl - Adding task set 1208.0 with 1 tasks resource profile 0
14:36:05.203 INFO  TaskSetManager - Starting task 0.0 in stage 1208.0 (TID 1039) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:36:05.203 INFO  Executor - Running task 0.0 in stage 1208.0 (TID 1039)
14:36:05.205 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
14:36:05.205 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.209 INFO  Executor - Finished task 0.0 in stage 1208.0 (TID 1039). 1922 bytes result sent to driver
14:36:05.210 INFO  TaskSetManager - Finished task 0.0 in stage 1208.0 (TID 1039) in 7 ms on localhost (executor driver) (1/1)
14:36:05.210 INFO  TaskSchedulerImpl - Removed TaskSet 1208.0, whose tasks have all completed, from pool 
14:36:05.210 INFO  DAGScheduler - ShuffleMapStage 1208 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
14:36:05.210 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.210 INFO  DAGScheduler - running: HashSet()
14:36:05.210 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1209, ResultStage 1210)
14:36:05.210 INFO  DAGScheduler - failed: HashSet()
14:36:05.210 INFO  DAGScheduler - Submitting ShuffleMapStage 1209 (MapPartitionsRDD[5380] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:36:05.211 INFO  MemoryStore - Block broadcast_1949 stored as values in memory (estimated size 52.4 KiB, free 1913.8 MiB)
14:36:05.211 INFO  MemoryStore - Block broadcast_1949_piece0 stored as bytes in memory (estimated size 17.3 KiB, free 1913.8 MiB)
14:36:05.211 INFO  BlockManagerInfo - Added broadcast_1949_piece0 in memory on localhost:34931 (size: 17.3 KiB, free: 1919.4 MiB)
14:36:05.212 INFO  SparkContext - Created broadcast 1949 from broadcast at DAGScheduler.scala:1580
14:36:05.212 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))
14:36:05.212 INFO  TaskSchedulerImpl - Adding task set 1209.0 with 1 tasks resource profile 0
14:36:05.212 INFO  TaskSetManager - Starting task 0.0 in stage 1209.0 (TID 1040) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:36:05.212 INFO  Executor - Running task 0.0 in stage 1209.0 (TID 1040)
14:36:05.214 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
14:36:05.214 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.218 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
14:36:05.218 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.221 INFO  Executor - Finished task 0.0 in stage 1209.0 (TID 1040). 1922 bytes result sent to driver
14:36:05.221 INFO  TaskSetManager - Finished task 0.0 in stage 1209.0 (TID 1040) in 9 ms on localhost (executor driver) (1/1)
14:36:05.221 INFO  TaskSchedulerImpl - Removed TaskSet 1209.0, whose tasks have all completed, from pool 
14:36:05.221 INFO  DAGScheduler - ShuffleMapStage 1209 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.011 s
14:36:05.221 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.221 INFO  DAGScheduler - running: HashSet()
14:36:05.221 INFO  DAGScheduler - waiting: HashSet(ResultStage 1210)
14:36:05.221 INFO  DAGScheduler - failed: HashSet()
14:36:05.221 INFO  DAGScheduler - Submitting ResultStage 1210 (MapPartitionsRDD[5382] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:36:05.222 INFO  MemoryStore - Block broadcast_1950 stored as values in memory (estimated size 53.6 KiB, free 1913.7 MiB)
14:36:05.223 INFO  MemoryStore - Block broadcast_1950_piece0 stored as bytes in memory (estimated size 18.0 KiB, free 1913.7 MiB)
14:36:05.223 INFO  BlockManagerInfo - Added broadcast_1950_piece0 in memory on localhost:34931 (size: 18.0 KiB, free: 1919.4 MiB)
14:36:05.223 INFO  SparkContext - Created broadcast 1950 from broadcast at DAGScheduler.scala:1580
14:36:05.223 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))
14:36:05.223 INFO  TaskSchedulerImpl - Adding task set 1210.0 with 1 tasks resource profile 0
14:36:05.224 INFO  TaskSetManager - Starting task 0.0 in stage 1210.0 (TID 1041) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.224 INFO  Executor - Running task 0.0 in stage 1210.0 (TID 1041)
14:36:05.226 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
14:36:05.226 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.228 INFO  Executor - Finished task 0.0 in stage 1210.0 (TID 1041). 2371 bytes result sent to driver
14:36:05.228 INFO  TaskSetManager - Finished task 0.0 in stage 1210.0 (TID 1041) in 5 ms on localhost (executor driver) (1/1)
14:36:05.228 INFO  TaskSchedulerImpl - Removed TaskSet 1210.0, whose tasks have all completed, from pool 
14:36:05.228 INFO  DAGScheduler - ResultStage 1210 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.007 s
14:36:05.228 INFO  DAGScheduler - Job 550 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.228 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1210: Stage finished
14:36:05.228 INFO  DAGScheduler - Job 550 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.037899 s
14:36:05.239 INFO  MemoryStore - Block broadcast_1951 stored as values in memory (estimated size 179.4 KiB, free 1913.5 MiB)
14:36:05.240 INFO  MemoryStore - Block broadcast_1951_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1913.5 MiB)
14:36:05.240 INFO  BlockManagerInfo - Added broadcast_1951_piece0 in memory on localhost:34931 (size: 7.9 KiB, free: 1919.4 MiB)
14:36:05.240 INFO  SparkContext - Created broadcast 1951 from broadcast at ReadsSparkSink.java:133
14:36:05.243 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:36:05.243 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:36:05.243 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:36:05.254 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:36:05.255 INFO  DAGScheduler - Registering RDD 5384 (mapToPair at SparkUtils.java:161) as input to shuffle 301
14:36:05.255 INFO  DAGScheduler - Got job 551 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:36:05.255 INFO  DAGScheduler - Final stage: ResultStage 1215 (runJob at SparkHadoopWriter.scala:83)
14:36:05.255 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1214)
14:36:05.255 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1214)
14:36:05.255 INFO  DAGScheduler - Submitting ShuffleMapStage 1214 (MapPartitionsRDD[5384] at mapToPair at SparkUtils.java:161), which has no missing parents
14:36:05.256 INFO  MemoryStore - Block broadcast_1952 stored as values in memory (estimated size 51.5 KiB, free 1913.5 MiB)
14:36:05.257 INFO  MemoryStore - Block broadcast_1952_piece0 stored as bytes in memory (estimated size 16.8 KiB, free 1913.4 MiB)
14:36:05.257 INFO  BlockManagerInfo - Added broadcast_1952_piece0 in memory on localhost:34931 (size: 16.8 KiB, free: 1919.4 MiB)
14:36:05.257 INFO  SparkContext - Created broadcast 1952 from broadcast at DAGScheduler.scala:1580
14:36:05.257 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))
14:36:05.257 INFO  TaskSchedulerImpl - Adding task set 1214.0 with 1 tasks resource profile 0
14:36:05.258 INFO  TaskSetManager - Starting task 0.0 in stage 1214.0 (TID 1042) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:36:05.258 INFO  Executor - Running task 0.0 in stage 1214.0 (TID 1042)
14:36:05.259 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
14:36:05.259 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.262 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
14:36:05.262 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.264 INFO  Executor - Finished task 0.0 in stage 1214.0 (TID 1042). 1922 bytes result sent to driver
14:36:05.264 INFO  TaskSetManager - Finished task 0.0 in stage 1214.0 (TID 1042) in 7 ms on localhost (executor driver) (1/1)
14:36:05.264 INFO  TaskSchedulerImpl - Removed TaskSet 1214.0, whose tasks have all completed, from pool 
14:36:05.264 INFO  DAGScheduler - ShuffleMapStage 1214 (mapToPair at SparkUtils.java:161) finished in 0.009 s
14:36:05.264 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.264 INFO  DAGScheduler - running: HashSet()
14:36:05.264 INFO  DAGScheduler - waiting: HashSet(ResultStage 1215)
14:36:05.264 INFO  DAGScheduler - failed: HashSet()
14:36:05.264 INFO  DAGScheduler - Submitting ResultStage 1215 (MapPartitionsRDD[5390] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:36:05.271 INFO  MemoryStore - Block broadcast_1953 stored as values in memory (estimated size 196.3 KiB, free 1913.2 MiB)
14:36:05.272 INFO  MemoryStore - Block broadcast_1953_piece0 stored as bytes in memory (estimated size 80.5 KiB, free 1913.2 MiB)
14:36:05.272 INFO  BlockManagerInfo - Added broadcast_1953_piece0 in memory on localhost:34931 (size: 80.5 KiB, free: 1919.3 MiB)
14:36:05.272 INFO  SparkContext - Created broadcast 1953 from broadcast at DAGScheduler.scala:1580
14:36:05.272 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))
14:36:05.272 INFO  TaskSchedulerImpl - Adding task set 1215.0 with 1 tasks resource profile 0
14:36:05.272 INFO  TaskSetManager - Starting task 0.0 in stage 1215.0 (TID 1043) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.273 INFO  Executor - Running task 0.0 in stage 1215.0 (TID 1043)
14:36:05.276 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
14:36:05.276 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.279 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:36:05.279 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:36:05.279 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:36:05.285 INFO  FileOutputCommitter - Saved output of task 'attempt_202506021436057125262929120631083_5390_m_000000_0' to file:/tmp/MarkDups17307935091905330972/MarkDups.sam.parts/_temporary/0/task_202506021436057125262929120631083_5390_m_000000
14:36:05.285 INFO  SparkHadoopMapRedUtil - attempt_202506021436057125262929120631083_5390_m_000000_0: Committed. Elapsed time: 0 ms.
14:36:05.285 INFO  Executor - Finished task 0.0 in stage 1215.0 (TID 1043). 1858 bytes result sent to driver
14:36:05.286 INFO  TaskSetManager - Finished task 0.0 in stage 1215.0 (TID 1043) in 14 ms on localhost (executor driver) (1/1)
14:36:05.286 INFO  TaskSchedulerImpl - Removed TaskSet 1215.0, whose tasks have all completed, from pool 
14:36:05.286 INFO  DAGScheduler - ResultStage 1215 (runJob at SparkHadoopWriter.scala:83) finished in 0.021 s
14:36:05.286 INFO  DAGScheduler - Job 551 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.286 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1215: Stage finished
14:36:05.286 INFO  DAGScheduler - Job 551 finished: runJob at SparkHadoopWriter.scala:83, took 0.031581 s
14:36:05.286 INFO  SparkHadoopWriter - Start to commit write Job job_202506021436057125262929120631083_5390.
14:36:05.289 INFO  SparkHadoopWriter - Write Job job_202506021436057125262929120631083_5390 committed. Elapsed time: 2 ms.
14:36:05.293 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups17307935091905330972/MarkDups.sam
14:36:05.295 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups17307935091905330972/MarkDups.sam done
14:36:05.295 INFO  MarkDuplicatesSpark - Shutting down engine
[June 2, 2025 at 2:36:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
14:36:05.310 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.310 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5749ecb-SNAPSHOT
14:36:05.310 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:36:05.310 INFO  MarkDuplicatesSpark - Executing as root@7f71e7f19701 on Linux v6.11.0-1014-azure amd64
14:36:05.310 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:36:05.310 INFO  MarkDuplicatesSpark - Start Date/Time: June 2, 2025 at 2:36:05 PM GMT
14:36:05.310 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.310 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.310 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:36:05.310 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:36:05.310 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:36:05.310 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:36:05.310 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:36:05.310 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:36:05.311 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:36:05.311 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:36:05.311 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:36:05.311 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:36:05.311 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:36:05.311 INFO  MarkDuplicatesSpark - Initializing engine
14:36:05.311 INFO  MarkDuplicatesSpark - Done initializing engine
14:36:05.311 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:36:05.312 INFO  MemoryStore - Block broadcast_1954 stored as values in memory (estimated size 305.5 KiB, free 1912.9 MiB)
14:36:05.319 INFO  MemoryStore - Block broadcast_1954_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1912.8 MiB)
14:36:05.319 INFO  BlockManagerInfo - Added broadcast_1954_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.2 MiB)
14:36:05.319 INFO  SparkContext - Created broadcast 1954 from newAPIHadoopFile at PathSplitSource.java:96
14:36:05.339 INFO  MemoryStore - Block broadcast_1955 stored as values in memory (estimated size 305.5 KiB, free 1912.5 MiB)
14:36:05.346 INFO  MemoryStore - Block broadcast_1955_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1912.4 MiB)
14:36:05.346 INFO  BlockManagerInfo - Added broadcast_1955_piece0 in memory on localhost:34931 (size: 64.0 KiB, free: 1919.2 MiB)
14:36:05.346 INFO  SparkContext - Created broadcast 1955 from newAPIHadoopFile at PathSplitSource.java:96
14:36:05.378 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:36:05.378 INFO  FileInputFormat - Total input files to process : 1
14:36:05.378 INFO  DAGScheduler - Registering RDD 5404 (mapToPair at SparkUtils.java:161) as input to shuffle 302
14:36:05.379 INFO  DAGScheduler - Got job 552 (collect at SparkUtils.java:205) with 1 output partitions
14:36:05.379 INFO  DAGScheduler - Final stage: ResultStage 1217 (collect at SparkUtils.java:205)
14:36:05.379 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1216)
14:36:05.379 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1216)
14:36:05.379 INFO  DAGScheduler - Submitting ShuffleMapStage 1216 (MapPartitionsRDD[5404] at mapToPair at SparkUtils.java:161), which has no missing parents
14:36:05.395 INFO  MemoryStore - Block broadcast_1956 stored as values in memory (estimated size 456.1 KiB, free 1912.0 MiB)
14:36:05.397 INFO  MemoryStore - Block broadcast_1956_piece0 stored as bytes in memory (estimated size 200.0 KiB, free 1911.8 MiB)
14:36:05.397 INFO  BlockManagerInfo - Added broadcast_1956_piece0 in memory on localhost:34931 (size: 200.0 KiB, free: 1919.0 MiB)
14:36:05.398 INFO  SparkContext - Created broadcast 1956 from broadcast at DAGScheduler.scala:1580
14:36:05.398 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))
14:36:05.398 INFO  TaskSchedulerImpl - Adding task set 1216.0 with 1 tasks resource profile 0
14:36:05.398 INFO  TaskSetManager - Starting task 0.0 in stage 1216.0 (TID 1044) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9653 bytes) 
14:36:05.398 INFO  Executor - Running task 0.0 in stage 1216.0 (TID 1044)
14:36:05.426 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam:0+678
14:36:05.430 INFO  Executor - Finished task 0.0 in stage 1216.0 (TID 1044). 1148 bytes result sent to driver
14:36:05.430 INFO  TaskSetManager - Finished task 0.0 in stage 1216.0 (TID 1044) in 32 ms on localhost (executor driver) (1/1)
14:36:05.430 INFO  TaskSchedulerImpl - Removed TaskSet 1216.0, whose tasks have all completed, from pool 
14:36:05.430 INFO  DAGScheduler - ShuffleMapStage 1216 (mapToPair at SparkUtils.java:161) finished in 0.051 s
14:36:05.430 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.430 INFO  DAGScheduler - running: HashSet()
14:36:05.430 INFO  DAGScheduler - waiting: HashSet(ResultStage 1217)
14:36:05.430 INFO  DAGScheduler - failed: HashSet()
14:36:05.431 INFO  DAGScheduler - Submitting ResultStage 1217 (MapPartitionsRDD[5407] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:36:05.431 INFO  MemoryStore - Block broadcast_1957 stored as values in memory (estimated size 7.4 KiB, free 1911.8 MiB)
14:36:05.431 INFO  MemoryStore - Block broadcast_1957_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1911.8 MiB)
14:36:05.431 INFO  BlockManagerInfo - Added broadcast_1957_piece0 in memory on localhost:34931 (size: 4.1 KiB, free: 1919.0 MiB)
14:36:05.432 INFO  SparkContext - Created broadcast 1957 from broadcast at DAGScheduler.scala:1580
14:36:05.432 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))
14:36:05.432 INFO  TaskSchedulerImpl - Adding task set 1217.0 with 1 tasks resource profile 0
14:36:05.432 INFO  TaskSetManager - Starting task 0.0 in stage 1217.0 (TID 1045) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.432 INFO  Executor - Running task 0.0 in stage 1217.0 (TID 1045)
14:36:05.433 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
14:36:05.433 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.434 INFO  Executor - Finished task 0.0 in stage 1217.0 (TID 1045). 2269 bytes result sent to driver
14:36:05.435 INFO  TaskSetManager - Finished task 0.0 in stage 1217.0 (TID 1045) in 3 ms on localhost (executor driver) (1/1)
14:36:05.435 INFO  TaskSchedulerImpl - Removed TaskSet 1217.0, whose tasks have all completed, from pool 
14:36:05.435 INFO  DAGScheduler - ResultStage 1217 (collect at SparkUtils.java:205) finished in 0.004 s
14:36:05.435 INFO  DAGScheduler - Job 552 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.435 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1217: Stage finished
14:36:05.435 INFO  DAGScheduler - Job 552 finished: collect at SparkUtils.java:205, took 0.057104 s
14:36:05.439 INFO  MemoryStore - Block broadcast_1958 stored as values in memory (estimated size 136.0 B, free 1911.8 MiB)
14:36:05.439 INFO  MemoryStore - Block broadcast_1958_piece0 stored as bytes in memory (estimated size 24.0 B, free 1911.8 MiB)
14:36:05.439 INFO  BlockManagerInfo - Added broadcast_1958_piece0 in memory on localhost:34931 (size: 24.0 B, free: 1919.0 MiB)
14:36:05.439 INFO  SparkContext - Created broadcast 1958 from broadcast at MarkDuplicatesSparkUtils.java:126
14:36:05.439 INFO  MemoryStore - Block broadcast_1959 stored as values in memory (estimated size 136.0 B, free 1911.8 MiB)
14:36:05.440 INFO  MemoryStore - Block broadcast_1959_piece0 stored as bytes in memory (estimated size 21.0 B, free 1911.8 MiB)
14:36:05.440 INFO  BlockManagerInfo - Added broadcast_1959_piece0 in memory on localhost:34931 (size: 21.0 B, free: 1919.0 MiB)
14:36:05.440 INFO  SparkContext - Created broadcast 1959 from broadcast at MarkDuplicatesSparkUtils.java:127
14:36:05.451 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:36:05.451 INFO  DAGScheduler - Registering RDD 5416 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 305
14:36:05.451 INFO  DAGScheduler - Registering RDD 5420 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 304
14:36:05.452 INFO  DAGScheduler - Registering RDD 5424 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 303
14:36:05.452 INFO  DAGScheduler - Got job 553 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:36:05.452 INFO  DAGScheduler - Final stage: ResultStage 1222 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:36:05.452 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1221)
14:36:05.452 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1221)
14:36:05.452 INFO  DAGScheduler - Submitting ShuffleMapStage 1219 (MapPartitionsRDD[5416] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:36:05.453 INFO  MemoryStore - Block broadcast_1960 stored as values in memory (estimated size 21.1 KiB, free 1911.8 MiB)
14:36:05.453 INFO  MemoryStore - Block broadcast_1960_piece0 stored as bytes in memory (estimated size 10.9 KiB, free 1911.8 MiB)
14:36:05.453 INFO  BlockManagerInfo - Added broadcast_1960_piece0 in memory on localhost:34931 (size: 10.9 KiB, free: 1919.0 MiB)
14:36:05.453 INFO  SparkContext - Created broadcast 1960 from broadcast at DAGScheduler.scala:1580
14:36:05.454 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))
14:36:05.454 INFO  TaskSchedulerImpl - Adding task set 1219.0 with 1 tasks resource profile 0
14:36:05.454 INFO  TaskSetManager - Starting task 0.0 in stage 1219.0 (TID 1046) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:36:05.454 INFO  Executor - Running task 0.0 in stage 1219.0 (TID 1046)
14:36:05.456 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
14:36:05.456 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.459 INFO  Executor - Finished task 0.0 in stage 1219.0 (TID 1046). 1922 bytes result sent to driver
14:36:05.460 INFO  TaskSetManager - Finished task 0.0 in stage 1219.0 (TID 1046) in 6 ms on localhost (executor driver) (1/1)
14:36:05.460 INFO  TaskSchedulerImpl - Removed TaskSet 1219.0, whose tasks have all completed, from pool 
14:36:05.460 INFO  DAGScheduler - ShuffleMapStage 1219 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
14:36:05.460 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.460 INFO  DAGScheduler - running: HashSet()
14:36:05.460 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1220, ShuffleMapStage 1221, ResultStage 1222)
14:36:05.460 INFO  DAGScheduler - failed: HashSet()
14:36:05.460 INFO  DAGScheduler - Submitting ShuffleMapStage 1220 (MapPartitionsRDD[5420] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:36:05.461 INFO  MemoryStore - Block broadcast_1961 stored as values in memory (estimated size 25.2 KiB, free 1911.7 MiB)
14:36:05.465 INFO  BlockManagerInfo - Removed broadcast_1945_piece0 on localhost:34931 in memory (size: 540.0 B, free: 1919.0 MiB)
14:36:05.465 INFO  MemoryStore - Block broadcast_1961_piece0 stored as bytes in memory (estimated size 13.1 KiB, free 1911.7 MiB)
14:36:05.465 INFO  BlockManagerInfo - Added broadcast_1961_piece0 in memory on localhost:34931 (size: 13.1 KiB, free: 1919.0 MiB)
14:36:05.465 INFO  SparkContext - Created broadcast 1961 from broadcast at DAGScheduler.scala:1580
14:36:05.465 INFO  BlockManagerInfo - Removed broadcast_1953_piece0 on localhost:34931 in memory (size: 80.5 KiB, free: 1919.0 MiB)
14:36:05.465 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))
14:36:05.465 INFO  TaskSchedulerImpl - Adding task set 1220.0 with 1 tasks resource profile 0
14:36:05.466 INFO  BlockManagerInfo - Removed broadcast_1942_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1919.1 MiB)
14:36:05.466 INFO  TaskSetManager - Starting task 0.0 in stage 1220.0 (TID 1047) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:36:05.466 INFO  Executor - Running task 0.0 in stage 1220.0 (TID 1047)
14:36:05.466 INFO  BlockManagerInfo - Removed broadcast_1951_piece0 on localhost:34931 in memory (size: 7.9 KiB, free: 1919.1 MiB)
14:36:05.466 INFO  BlockManagerInfo - Removed broadcast_1950_piece0 on localhost:34931 in memory (size: 18.0 KiB, free: 1919.1 MiB)
14:36:05.467 INFO  BlockManagerInfo - Removed broadcast_1946_piece0 on localhost:34931 in memory (size: 209.0 B, free: 1919.1 MiB)
14:36:05.467 INFO  BlockManagerInfo - Removed broadcast_1956_piece0 on localhost:34931 in memory (size: 200.0 KiB, free: 1919.3 MiB)
14:36:05.467 INFO  BlockManagerInfo - Removed broadcast_1947_piece0 on localhost:34931 in memory (size: 19.8 KiB, free: 1919.3 MiB)
14:36:05.468 INFO  BlockManagerInfo - Removed broadcast_1948_piece0 on localhost:34931 in memory (size: 22.0 KiB, free: 1919.4 MiB)
14:36:05.468 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
14:36:05.468 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.468 INFO  BlockManagerInfo - Removed broadcast_1952_piece0 on localhost:34931 in memory (size: 16.8 KiB, free: 1919.4 MiB)
14:36:05.469 INFO  BlockManagerInfo - Removed broadcast_1949_piece0 on localhost:34931 in memory (size: 17.3 KiB, free: 1919.4 MiB)
14:36:05.469 INFO  BlockManagerInfo - Removed broadcast_1954_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1919.5 MiB)
14:36:05.469 INFO  BlockManagerInfo - Removed broadcast_1957_piece0 on localhost:34931 in memory (size: 4.1 KiB, free: 1919.5 MiB)
14:36:05.471 INFO  Executor - Finished task 0.0 in stage 1220.0 (TID 1047). 1922 bytes result sent to driver
14:36:05.472 INFO  TaskSetManager - Finished task 0.0 in stage 1220.0 (TID 1047) in 6 ms on localhost (executor driver) (1/1)
14:36:05.472 INFO  TaskSchedulerImpl - Removed TaskSet 1220.0, whose tasks have all completed, from pool 
14:36:05.472 INFO  DAGScheduler - ShuffleMapStage 1220 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.011 s
14:36:05.472 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.472 INFO  DAGScheduler - running: HashSet()
14:36:05.472 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1221, ResultStage 1222)
14:36:05.472 INFO  DAGScheduler - failed: HashSet()
14:36:05.472 INFO  DAGScheduler - Submitting ShuffleMapStage 1221 (MapPartitionsRDD[5424] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:36:05.473 INFO  MemoryStore - Block broadcast_1962 stored as values in memory (estimated size 15.9 KiB, free 1913.9 MiB)
14:36:05.473 INFO  MemoryStore - Block broadcast_1962_piece0 stored as bytes in memory (estimated size 8.3 KiB, free 1913.9 MiB)
14:36:05.473 INFO  BlockManagerInfo - Added broadcast_1962_piece0 in memory on localhost:34931 (size: 8.3 KiB, free: 1919.5 MiB)
14:36:05.473 INFO  SparkContext - Created broadcast 1962 from broadcast at DAGScheduler.scala:1580
14:36:05.473 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))
14:36:05.473 INFO  TaskSchedulerImpl - Adding task set 1221.0 with 1 tasks resource profile 0
14:36:05.474 INFO  TaskSetManager - Starting task 0.0 in stage 1221.0 (TID 1048) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:36:05.474 INFO  Executor - Running task 0.0 in stage 1221.0 (TID 1048)
14:36:05.475 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
14:36:05.475 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.477 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
14:36:05.477 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.478 INFO  Executor - Finished task 0.0 in stage 1221.0 (TID 1048). 1922 bytes result sent to driver
14:36:05.478 INFO  TaskSetManager - Finished task 0.0 in stage 1221.0 (TID 1048) in 4 ms on localhost (executor driver) (1/1)
14:36:05.478 INFO  TaskSchedulerImpl - Removed TaskSet 1221.0, whose tasks have all completed, from pool 
14:36:05.478 INFO  DAGScheduler - ShuffleMapStage 1221 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
14:36:05.478 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.478 INFO  DAGScheduler - running: HashSet()
14:36:05.478 INFO  DAGScheduler - waiting: HashSet(ResultStage 1222)
14:36:05.478 INFO  DAGScheduler - failed: HashSet()
14:36:05.478 INFO  DAGScheduler - Submitting ResultStage 1222 (MapPartitionsRDD[5426] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:36:05.479 INFO  MemoryStore - Block broadcast_1963 stored as values in memory (estimated size 17.1 KiB, free 1913.9 MiB)
14:36:05.479 INFO  MemoryStore - Block broadcast_1963_piece0 stored as bytes in memory (estimated size 9.0 KiB, free 1913.9 MiB)
14:36:05.479 INFO  BlockManagerInfo - Added broadcast_1963_piece0 in memory on localhost:34931 (size: 9.0 KiB, free: 1919.4 MiB)
14:36:05.479 INFO  SparkContext - Created broadcast 1963 from broadcast at DAGScheduler.scala:1580
14:36:05.479 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))
14:36:05.479 INFO  TaskSchedulerImpl - Adding task set 1222.0 with 1 tasks resource profile 0
14:36:05.480 INFO  TaskSetManager - Starting task 0.0 in stage 1222.0 (TID 1049) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.480 INFO  Executor - Running task 0.0 in stage 1222.0 (TID 1049)
14:36:05.481 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
14:36:05.481 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.482 INFO  Executor - Finished task 0.0 in stage 1222.0 (TID 1049). 1887 bytes result sent to driver
14:36:05.482 INFO  TaskSetManager - Finished task 0.0 in stage 1222.0 (TID 1049) in 2 ms on localhost (executor driver) (1/1)
14:36:05.482 INFO  TaskSchedulerImpl - Removed TaskSet 1222.0, whose tasks have all completed, from pool 
14:36:05.482 INFO  DAGScheduler - ResultStage 1222 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.004 s
14:36:05.482 INFO  DAGScheduler - Job 553 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.482 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1222: Stage finished
14:36:05.482 INFO  DAGScheduler - Job 553 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.031393 s
14:36:05.492 INFO  MemoryStore - Block broadcast_1964 stored as values in memory (estimated size 5.6 KiB, free 1913.9 MiB)
14:36:05.492 INFO  MemoryStore - Block broadcast_1964_piece0 stored as bytes in memory (estimated size 500.0 B, free 1913.9 MiB)
14:36:05.492 INFO  BlockManagerInfo - Added broadcast_1964_piece0 in memory on localhost:34931 (size: 500.0 B, free: 1919.4 MiB)
14:36:05.493 INFO  SparkContext - Created broadcast 1964 from broadcast at ReadsSparkSink.java:133
14:36:05.496 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:36:05.496 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:36:05.496 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:36:05.507 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:36:05.507 INFO  DAGScheduler - Registering RDD 5428 (mapToPair at SparkUtils.java:161) as input to shuffle 306
14:36:05.508 INFO  DAGScheduler - Got job 554 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:36:05.508 INFO  DAGScheduler - Final stage: ResultStage 1227 (runJob at SparkHadoopWriter.scala:83)
14:36:05.508 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1226)
14:36:05.508 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1226)
14:36:05.508 INFO  DAGScheduler - Submitting ShuffleMapStage 1226 (MapPartitionsRDD[5428] at mapToPair at SparkUtils.java:161), which has no missing parents
14:36:05.508 INFO  MemoryStore - Block broadcast_1965 stored as values in memory (estimated size 15.0 KiB, free 1913.9 MiB)
14:36:05.509 INFO  MemoryStore - Block broadcast_1965_piece0 stored as bytes in memory (estimated size 7.8 KiB, free 1913.8 MiB)
14:36:05.509 INFO  BlockManagerInfo - Added broadcast_1965_piece0 in memory on localhost:34931 (size: 7.8 KiB, free: 1919.4 MiB)
14:36:05.509 INFO  SparkContext - Created broadcast 1965 from broadcast at DAGScheduler.scala:1580
14:36:05.509 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))
14:36:05.509 INFO  TaskSchedulerImpl - Adding task set 1226.0 with 1 tasks resource profile 0
14:36:05.510 INFO  TaskSetManager - Starting task 0.0 in stage 1226.0 (TID 1050) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:36:05.510 INFO  Executor - Running task 0.0 in stage 1226.0 (TID 1050)
14:36:05.511 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
14:36:05.511 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.513 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
14:36:05.513 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.514 INFO  Executor - Finished task 0.0 in stage 1226.0 (TID 1050). 1879 bytes result sent to driver
14:36:05.514 INFO  TaskSetManager - Finished task 0.0 in stage 1226.0 (TID 1050) in 4 ms on localhost (executor driver) (1/1)
14:36:05.514 INFO  TaskSchedulerImpl - Removed TaskSet 1226.0, whose tasks have all completed, from pool 
14:36:05.514 INFO  DAGScheduler - ShuffleMapStage 1226 (mapToPair at SparkUtils.java:161) finished in 0.006 s
14:36:05.514 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.514 INFO  DAGScheduler - running: HashSet()
14:36:05.514 INFO  DAGScheduler - waiting: HashSet(ResultStage 1227)
14:36:05.514 INFO  DAGScheduler - failed: HashSet()
14:36:05.514 INFO  DAGScheduler - Submitting ResultStage 1227 (MapPartitionsRDD[5434] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:36:05.520 INFO  MemoryStore - Block broadcast_1966 stored as values in memory (estimated size 159.8 KiB, free 1913.7 MiB)
14:36:05.521 INFO  MemoryStore - Block broadcast_1966_piece0 stored as bytes in memory (estimated size 71.6 KiB, free 1913.6 MiB)
14:36:05.521 INFO  BlockManagerInfo - Added broadcast_1966_piece0 in memory on localhost:34931 (size: 71.6 KiB, free: 1919.4 MiB)
14:36:05.522 INFO  SparkContext - Created broadcast 1966 from broadcast at DAGScheduler.scala:1580
14:36:05.522 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))
14:36:05.522 INFO  TaskSchedulerImpl - Adding task set 1227.0 with 1 tasks resource profile 0
14:36:05.522 INFO  TaskSetManager - Starting task 0.0 in stage 1227.0 (TID 1051) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.522 INFO  Executor - Running task 0.0 in stage 1227.0 (TID 1051)
14:36:05.527 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
14:36:05.527 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.529 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:36:05.529 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:36:05.529 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:36:05.536 INFO  FileOutputCommitter - Saved output of task 'attempt_202506021436051906912553048738317_5434_m_000000_0' to file:/tmp/MarkDups4780690222968143700/MarkDups.sam.parts/_temporary/0/task_202506021436051906912553048738317_5434_m_000000
14:36:05.536 INFO  SparkHadoopMapRedUtil - attempt_202506021436051906912553048738317_5434_m_000000_0: Committed. Elapsed time: 0 ms.
14:36:05.536 INFO  Executor - Finished task 0.0 in stage 1227.0 (TID 1051). 1858 bytes result sent to driver
14:36:05.536 INFO  TaskSetManager - Finished task 0.0 in stage 1227.0 (TID 1051) in 14 ms on localhost (executor driver) (1/1)
14:36:05.537 INFO  TaskSchedulerImpl - Removed TaskSet 1227.0, whose tasks have all completed, from pool 
14:36:05.537 INFO  DAGScheduler - ResultStage 1227 (runJob at SparkHadoopWriter.scala:83) finished in 0.022 s
14:36:05.537 INFO  DAGScheduler - Job 554 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.537 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1227: Stage finished
14:36:05.537 INFO  DAGScheduler - Job 554 finished: runJob at SparkHadoopWriter.scala:83, took 0.029652 s
14:36:05.537 INFO  SparkHadoopWriter - Start to commit write Job job_202506021436051906912553048738317_5434.
14:36:05.540 INFO  SparkHadoopWriter - Write Job job_202506021436051906912553048738317_5434 committed. Elapsed time: 2 ms.
14:36:05.544 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups4780690222968143700/MarkDups.sam
14:36:05.546 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups4780690222968143700/MarkDups.sam done
14:36:05.546 INFO  MarkDuplicatesSpark - Shutting down engine
[June 2, 2025 at 2:36:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
14:36:05.565 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.565 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5749ecb-SNAPSHOT
14:36:05.565 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:36:05.565 INFO  MarkDuplicatesSpark - Executing as root@7f71e7f19701 on Linux v6.11.0-1014-azure amd64
14:36:05.565 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:36:05.565 INFO  MarkDuplicatesSpark - Start Date/Time: June 2, 2025 at 2:36:05 PM GMT
14:36:05.565 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.565 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:36:05.565 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:36:05.565 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:36:05.565 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:36:05.565 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:36:05.565 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:36:05.565 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:36:05.565 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:36:05.565 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:36:05.565 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:36:05.565 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:36:05.565 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:36:05.565 INFO  MarkDuplicatesSpark - Initializing engine
14:36:05.565 INFO  MarkDuplicatesSpark - Done initializing engine
14:36:05.565 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:36:05.567 INFO  MemoryStore - Block broadcast_1967 stored as values in memory (estimated size 305.5 KiB, free 1913.3 MiB)
14:36:05.574 INFO  MemoryStore - Block broadcast_1967_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1913.3 MiB)
14:36:05.574 INFO  BlockManagerInfo - Added broadcast_1967_piece0 in memory on localhost:34931 (size: 64.1 KiB, free: 1919.3 MiB)
14:36:05.575 INFO  SparkContext - Created broadcast 1967 from newAPIHadoopFile at PathSplitSource.java:96
14:36:05.596 INFO  MemoryStore - Block broadcast_1968 stored as values in memory (estimated size 305.5 KiB, free 1913.0 MiB)
14:36:05.603 INFO  MemoryStore - Block broadcast_1968_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1912.9 MiB)
14:36:05.603 INFO  BlockManagerInfo - Added broadcast_1968_piece0 in memory on localhost:34931 (size: 64.1 KiB, free: 1919.2 MiB)
14:36:05.603 INFO  SparkContext - Created broadcast 1968 from newAPIHadoopFile at PathSplitSource.java:96
14:36:05.635 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:36:05.635 INFO  FileInputFormat - Total input files to process : 1
14:36:05.636 INFO  DAGScheduler - Registering RDD 5448 (mapToPair at SparkUtils.java:161) as input to shuffle 307
14:36:05.636 INFO  DAGScheduler - Got job 555 (collect at SparkUtils.java:205) with 1 output partitions
14:36:05.636 INFO  DAGScheduler - Final stage: ResultStage 1229 (collect at SparkUtils.java:205)
14:36:05.636 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1228)
14:36:05.636 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1228)
14:36:05.636 INFO  DAGScheduler - Submitting ShuffleMapStage 1228 (MapPartitionsRDD[5448] at mapToPair at SparkUtils.java:161), which has no missing parents
14:36:05.653 INFO  MemoryStore - Block broadcast_1969 stored as values in memory (estimated size 480.2 KiB, free 1912.4 MiB)
14:36:05.655 INFO  MemoryStore - Block broadcast_1969_piece0 stored as bytes in memory (estimated size 206.2 KiB, free 1912.2 MiB)
14:36:05.655 INFO  BlockManagerInfo - Added broadcast_1969_piece0 in memory on localhost:34931 (size: 206.2 KiB, free: 1919.0 MiB)
14:36:05.655 INFO  SparkContext - Created broadcast 1969 from broadcast at DAGScheduler.scala:1580
14:36:05.655 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))
14:36:05.655 INFO  TaskSchedulerImpl - Adding task set 1228.0 with 1 tasks resource profile 0
14:36:05.656 INFO  TaskSetManager - Starting task 0.0 in stage 1228.0 (TID 1052) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9673 bytes) 
14:36:05.656 INFO  Executor - Running task 0.0 in stage 1228.0 (TID 1052)
14:36:05.684 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam:0+5416
14:36:05.689 INFO  Executor - Finished task 0.0 in stage 1228.0 (TID 1052). 1148 bytes result sent to driver
14:36:05.689 INFO  TaskSetManager - Finished task 0.0 in stage 1228.0 (TID 1052) in 33 ms on localhost (executor driver) (1/1)
14:36:05.689 INFO  TaskSchedulerImpl - Removed TaskSet 1228.0, whose tasks have all completed, from pool 
14:36:05.689 INFO  DAGScheduler - ShuffleMapStage 1228 (mapToPair at SparkUtils.java:161) finished in 0.053 s
14:36:05.690 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.690 INFO  DAGScheduler - running: HashSet()
14:36:05.690 INFO  DAGScheduler - waiting: HashSet(ResultStage 1229)
14:36:05.690 INFO  DAGScheduler - failed: HashSet()
14:36:05.690 INFO  DAGScheduler - Submitting ResultStage 1229 (MapPartitionsRDD[5451] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:36:05.690 INFO  MemoryStore - Block broadcast_1970 stored as values in memory (estimated size 7.4 KiB, free 1912.2 MiB)
14:36:05.691 INFO  MemoryStore - Block broadcast_1970_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1912.2 MiB)
14:36:05.691 INFO  BlockManagerInfo - Added broadcast_1970_piece0 in memory on localhost:34931 (size: 4.1 KiB, free: 1919.0 MiB)
14:36:05.691 INFO  SparkContext - Created broadcast 1970 from broadcast at DAGScheduler.scala:1580
14:36:05.691 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))
14:36:05.691 INFO  TaskSchedulerImpl - Adding task set 1229.0 with 1 tasks resource profile 0
14:36:05.691 INFO  TaskSetManager - Starting task 0.0 in stage 1229.0 (TID 1053) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.692 INFO  Executor - Running task 0.0 in stage 1229.0 (TID 1053)
14:36:05.692 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
14:36:05.692 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.694 INFO  Executor - Finished task 0.0 in stage 1229.0 (TID 1053). 2039 bytes result sent to driver
14:36:05.694 INFO  TaskSetManager - Finished task 0.0 in stage 1229.0 (TID 1053) in 3 ms on localhost (executor driver) (1/1)
14:36:05.694 INFO  TaskSchedulerImpl - Removed TaskSet 1229.0, whose tasks have all completed, from pool 
14:36:05.694 INFO  DAGScheduler - ResultStage 1229 (collect at SparkUtils.java:205) finished in 0.004 s
14:36:05.694 INFO  DAGScheduler - Job 555 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.694 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1229: Stage finished
14:36:05.694 INFO  DAGScheduler - Job 555 finished: collect at SparkUtils.java:205, took 0.059585 s
14:36:05.698 INFO  MemoryStore - Block broadcast_1971 stored as values in memory (estimated size 392.0 B, free 1912.2 MiB)
14:36:05.698 INFO  MemoryStore - Block broadcast_1971_piece0 stored as bytes in memory (estimated size 33.0 B, free 1912.2 MiB)
14:36:05.699 INFO  BlockManagerInfo - Added broadcast_1971_piece0 in memory on localhost:34931 (size: 33.0 B, free: 1919.0 MiB)
14:36:05.699 INFO  SparkContext - Created broadcast 1971 from broadcast at MarkDuplicatesSparkUtils.java:126
14:36:05.699 INFO  MemoryStore - Block broadcast_1972 stored as values in memory (estimated size 144.0 B, free 1912.2 MiB)
14:36:05.699 INFO  MemoryStore - Block broadcast_1972_piece0 stored as bytes in memory (estimated size 28.0 B, free 1912.2 MiB)
14:36:05.699 INFO  BlockManagerInfo - Added broadcast_1972_piece0 in memory on localhost:34931 (size: 28.0 B, free: 1919.0 MiB)
14:36:05.700 INFO  SparkContext - Created broadcast 1972 from broadcast at MarkDuplicatesSparkUtils.java:127
14:36:05.712 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:36:05.712 INFO  DAGScheduler - Registering RDD 5460 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 310
14:36:05.712 INFO  DAGScheduler - Registering RDD 5464 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 309
14:36:05.712 INFO  DAGScheduler - Registering RDD 5468 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 308
14:36:05.712 INFO  DAGScheduler - Got job 556 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:36:05.712 INFO  DAGScheduler - Final stage: ResultStage 1234 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:36:05.712 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1233)
14:36:05.712 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1233)
14:36:05.712 INFO  DAGScheduler - Submitting ShuffleMapStage 1231 (MapPartitionsRDD[5460] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:36:05.713 INFO  MemoryStore - Block broadcast_1973 stored as values in memory (estimated size 45.2 KiB, free 1912.2 MiB)
14:36:05.714 INFO  MemoryStore - Block broadcast_1973_piece0 stored as bytes in memory (estimated size 17.1 KiB, free 1912.2 MiB)
14:36:05.714 INFO  BlockManagerInfo - Added broadcast_1973_piece0 in memory on localhost:34931 (size: 17.1 KiB, free: 1919.0 MiB)
14:36:05.714 INFO  SparkContext - Created broadcast 1973 from broadcast at DAGScheduler.scala:1580
14:36:05.714 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))
14:36:05.714 INFO  TaskSchedulerImpl - Adding task set 1231.0 with 1 tasks resource profile 0
14:36:05.715 INFO  TaskSetManager - Starting task 0.0 in stage 1231.0 (TID 1054) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:36:05.715 INFO  Executor - Running task 0.0 in stage 1231.0 (TID 1054)
14:36:05.717 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
14:36:05.717 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.719 INFO  Executor - Finished task 0.0 in stage 1231.0 (TID 1054). 1922 bytes result sent to driver
14:36:05.720 INFO  TaskSetManager - Finished task 0.0 in stage 1231.0 (TID 1054) in 4 ms on localhost (executor driver) (1/1)
14:36:05.720 INFO  TaskSchedulerImpl - Removed TaskSet 1231.0, whose tasks have all completed, from pool 
14:36:05.720 INFO  DAGScheduler - ShuffleMapStage 1231 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
14:36:05.720 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.720 INFO  DAGScheduler - running: HashSet()
14:36:05.720 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1232, ShuffleMapStage 1233, ResultStage 1234)
14:36:05.720 INFO  DAGScheduler - failed: HashSet()
14:36:05.720 INFO  DAGScheduler - Submitting ShuffleMapStage 1232 (MapPartitionsRDD[5464] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:36:05.721 INFO  MemoryStore - Block broadcast_1974 stored as values in memory (estimated size 49.3 KiB, free 1912.1 MiB)
14:36:05.721 INFO  MemoryStore - Block broadcast_1974_piece0 stored as bytes in memory (estimated size 19.3 KiB, free 1912.1 MiB)
14:36:05.721 INFO  BlockManagerInfo - Added broadcast_1974_piece0 in memory on localhost:34931 (size: 19.3 KiB, free: 1919.0 MiB)
14:36:05.721 INFO  SparkContext - Created broadcast 1974 from broadcast at DAGScheduler.scala:1580
14:36:05.722 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))
14:36:05.722 INFO  TaskSchedulerImpl - Adding task set 1232.0 with 1 tasks resource profile 0
14:36:05.722 INFO  TaskSetManager - Starting task 0.0 in stage 1232.0 (TID 1055) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:36:05.722 INFO  Executor - Running task 0.0 in stage 1232.0 (TID 1055)
14:36:05.724 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
14:36:05.724 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.727 INFO  Executor - Finished task 0.0 in stage 1232.0 (TID 1055). 1922 bytes result sent to driver
14:36:05.727 INFO  TaskSetManager - Finished task 0.0 in stage 1232.0 (TID 1055) in 5 ms on localhost (executor driver) (1/1)
14:36:05.727 INFO  TaskSchedulerImpl - Removed TaskSet 1232.0, whose tasks have all completed, from pool 
14:36:05.727 INFO  DAGScheduler - ShuffleMapStage 1232 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
14:36:05.727 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.727 INFO  DAGScheduler - running: HashSet()
14:36:05.727 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1233, ResultStage 1234)
14:36:05.727 INFO  DAGScheduler - failed: HashSet()
14:36:05.727 INFO  DAGScheduler - Submitting ShuffleMapStage 1233 (MapPartitionsRDD[5468] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:36:05.728 INFO  MemoryStore - Block broadcast_1975 stored as values in memory (estimated size 40.0 KiB, free 1912.1 MiB)
14:36:05.728 INFO  MemoryStore - Block broadcast_1975_piece0 stored as bytes in memory (estimated size 14.5 KiB, free 1912.0 MiB)
14:36:05.728 INFO  BlockManagerInfo - Added broadcast_1975_piece0 in memory on localhost:34931 (size: 14.5 KiB, free: 1919.0 MiB)
14:36:05.729 INFO  SparkContext - Created broadcast 1975 from broadcast at DAGScheduler.scala:1580
14:36:05.729 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))
14:36:05.729 INFO  TaskSchedulerImpl - Adding task set 1233.0 with 1 tasks resource profile 0
14:36:05.729 INFO  TaskSetManager - Starting task 0.0 in stage 1233.0 (TID 1056) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:36:05.729 INFO  Executor - Running task 0.0 in stage 1233.0 (TID 1056)
14:36:05.730 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
14:36:05.730 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.732 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
14:36:05.732 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.733 INFO  Executor - Finished task 0.0 in stage 1233.0 (TID 1056). 1879 bytes result sent to driver
14:36:05.733 INFO  TaskSetManager - Finished task 0.0 in stage 1233.0 (TID 1056) in 4 ms on localhost (executor driver) (1/1)
14:36:05.733 INFO  TaskSchedulerImpl - Removed TaskSet 1233.0, whose tasks have all completed, from pool 
14:36:05.733 INFO  DAGScheduler - ShuffleMapStage 1233 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
14:36:05.733 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.733 INFO  DAGScheduler - running: HashSet()
14:36:05.733 INFO  DAGScheduler - waiting: HashSet(ResultStage 1234)
14:36:05.733 INFO  DAGScheduler - failed: HashSet()
14:36:05.733 INFO  DAGScheduler - Submitting ResultStage 1234 (MapPartitionsRDD[5470] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:36:05.734 INFO  MemoryStore - Block broadcast_1976 stored as values in memory (estimated size 41.2 KiB, free 1912.0 MiB)
14:36:05.735 INFO  MemoryStore - Block broadcast_1976_piece0 stored as bytes in memory (estimated size 15.3 KiB, free 1912.0 MiB)
14:36:05.735 INFO  BlockManagerInfo - Added broadcast_1976_piece0 in memory on localhost:34931 (size: 15.3 KiB, free: 1919.0 MiB)
14:36:05.735 INFO  SparkContext - Created broadcast 1976 from broadcast at DAGScheduler.scala:1580
14:36:05.735 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))
14:36:05.735 INFO  TaskSchedulerImpl - Adding task set 1234.0 with 1 tasks resource profile 0
14:36:05.735 INFO  TaskSetManager - Starting task 0.0 in stage 1234.0 (TID 1057) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.736 INFO  Executor - Running task 0.0 in stage 1234.0 (TID 1057)
14:36:05.737 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
14:36:05.737 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.743 INFO  Executor - Finished task 0.0 in stage 1234.0 (TID 1057). 2030 bytes result sent to driver
14:36:05.744 INFO  BlockManagerInfo - Removed broadcast_1975_piece0 on localhost:34931 in memory (size: 14.5 KiB, free: 1919.0 MiB)
14:36:05.744 INFO  TaskSetManager - Finished task 0.0 in stage 1234.0 (TID 1057) in 9 ms on localhost (executor driver) (1/1)
14:36:05.744 INFO  TaskSchedulerImpl - Removed TaskSet 1234.0, whose tasks have all completed, from pool 
14:36:05.744 INFO  DAGScheduler - ResultStage 1234 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.011 s
14:36:05.744 INFO  BlockManagerInfo - Removed broadcast_1955_piece0 on localhost:34931 in memory (size: 64.0 KiB, free: 1919.1 MiB)
14:36:05.744 INFO  DAGScheduler - Job 556 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.744 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1234: Stage finished
14:36:05.744 INFO  DAGScheduler - Job 556 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.032661 s
14:36:05.745 INFO  BlockManagerInfo - Removed broadcast_1959_piece0 on localhost:34931 in memory (size: 21.0 B, free: 1919.1 MiB)
14:36:05.745 INFO  BlockManagerInfo - Removed broadcast_1966_piece0 on localhost:34931 in memory (size: 71.6 KiB, free: 1919.1 MiB)
14:36:05.745 INFO  BlockManagerInfo - Removed broadcast_1961_piece0 on localhost:34931 in memory (size: 13.1 KiB, free: 1919.1 MiB)
14:36:05.746 INFO  BlockManagerInfo - Removed broadcast_1969_piece0 on localhost:34931 in memory (size: 206.2 KiB, free: 1919.3 MiB)
14:36:05.746 INFO  BlockManagerInfo - Removed broadcast_1962_piece0 on localhost:34931 in memory (size: 8.3 KiB, free: 1919.3 MiB)
14:36:05.746 INFO  BlockManagerInfo - Removed broadcast_1973_piece0 on localhost:34931 in memory (size: 17.1 KiB, free: 1919.4 MiB)
14:36:05.747 INFO  BlockManagerInfo - Removed broadcast_1958_piece0 on localhost:34931 in memory (size: 24.0 B, free: 1919.4 MiB)
14:36:05.747 INFO  BlockManagerInfo - Removed broadcast_1967_piece0 on localhost:34931 in memory (size: 64.1 KiB, free: 1919.4 MiB)
14:36:05.748 INFO  BlockManagerInfo - Removed broadcast_1964_piece0 on localhost:34931 in memory (size: 500.0 B, free: 1919.4 MiB)
14:36:05.748 INFO  BlockManagerInfo - Removed broadcast_1974_piece0 on localhost:34931 in memory (size: 19.3 KiB, free: 1919.4 MiB)
14:36:05.748 INFO  BlockManagerInfo - Removed broadcast_1963_piece0 on localhost:34931 in memory (size: 9.0 KiB, free: 1919.5 MiB)
14:36:05.749 INFO  BlockManagerInfo - Removed broadcast_1970_piece0 on localhost:34931 in memory (size: 4.1 KiB, free: 1919.5 MiB)
14:36:05.749 INFO  BlockManagerInfo - Removed broadcast_1965_piece0 on localhost:34931 in memory (size: 7.8 KiB, free: 1919.5 MiB)
14:36:05.749 INFO  BlockManagerInfo - Removed broadcast_1960_piece0 on localhost:34931 in memory (size: 10.9 KiB, free: 1919.5 MiB)
14:36:05.756 INFO  MemoryStore - Block broadcast_1977 stored as values in memory (estimated size 93.5 KiB, free 1913.8 MiB)
14:36:05.757 INFO  MemoryStore - Block broadcast_1977_piece0 stored as bytes in memory (estimated size 5.6 KiB, free 1913.8 MiB)
14:36:05.757 INFO  BlockManagerInfo - Added broadcast_1977_piece0 in memory on localhost:34931 (size: 5.6 KiB, free: 1919.5 MiB)
14:36:05.757 INFO  SparkContext - Created broadcast 1977 from broadcast at ReadsSparkSink.java:133
14:36:05.760 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:36:05.761 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:36:05.761 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:36:05.772 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:36:05.772 INFO  DAGScheduler - Registering RDD 5472 (mapToPair at SparkUtils.java:161) as input to shuffle 311
14:36:05.773 INFO  DAGScheduler - Got job 557 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:36:05.773 INFO  DAGScheduler - Final stage: ResultStage 1239 (runJob at SparkHadoopWriter.scala:83)
14:36:05.773 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1238)
14:36:05.773 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1238)
14:36:05.773 INFO  DAGScheduler - Submitting ShuffleMapStage 1238 (MapPartitionsRDD[5472] at mapToPair at SparkUtils.java:161), which has no missing parents
14:36:05.774 INFO  MemoryStore - Block broadcast_1978 stored as values in memory (estimated size 39.1 KiB, free 1913.8 MiB)
14:36:05.774 INFO  MemoryStore - Block broadcast_1978_piece0 stored as bytes in memory (estimated size 14.1 KiB, free 1913.8 MiB)
14:36:05.774 INFO  BlockManagerInfo - Added broadcast_1978_piece0 in memory on localhost:34931 (size: 14.1 KiB, free: 1919.5 MiB)
14:36:05.774 INFO  SparkContext - Created broadcast 1978 from broadcast at DAGScheduler.scala:1580
14:36:05.774 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))
14:36:05.775 INFO  TaskSchedulerImpl - Adding task set 1238.0 with 1 tasks resource profile 0
14:36:05.775 INFO  TaskSetManager - Starting task 0.0 in stage 1238.0 (TID 1058) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:36:05.775 INFO  Executor - Running task 0.0 in stage 1238.0 (TID 1058)
14:36:05.777 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
14:36:05.777 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.778 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
14:36:05.778 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.779 INFO  Executor - Finished task 0.0 in stage 1238.0 (TID 1058). 1922 bytes result sent to driver
14:36:05.780 INFO  TaskSetManager - Finished task 0.0 in stage 1238.0 (TID 1058) in 5 ms on localhost (executor driver) (1/1)
14:36:05.780 INFO  TaskSchedulerImpl - Removed TaskSet 1238.0, whose tasks have all completed, from pool 
14:36:05.780 INFO  DAGScheduler - ShuffleMapStage 1238 (mapToPair at SparkUtils.java:161) finished in 0.007 s
14:36:05.780 INFO  DAGScheduler - looking for newly runnable stages
14:36:05.780 INFO  DAGScheduler - running: HashSet()
14:36:05.780 INFO  DAGScheduler - waiting: HashSet(ResultStage 1239)
14:36:05.780 INFO  DAGScheduler - failed: HashSet()
14:36:05.780 INFO  DAGScheduler - Submitting ResultStage 1239 (MapPartitionsRDD[5478] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:36:05.786 INFO  MemoryStore - Block broadcast_1979 stored as values in memory (estimated size 183.9 KiB, free 1913.6 MiB)
14:36:05.787 INFO  MemoryStore - Block broadcast_1979_piece0 stored as bytes in memory (estimated size 77.8 KiB, free 1913.5 MiB)
14:36:05.787 INFO  BlockManagerInfo - Added broadcast_1979_piece0 in memory on localhost:34931 (size: 77.8 KiB, free: 1919.4 MiB)
14:36:05.787 INFO  SparkContext - Created broadcast 1979 from broadcast at DAGScheduler.scala:1580
14:36:05.787 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))
14:36:05.788 INFO  TaskSchedulerImpl - Adding task set 1239.0 with 1 tasks resource profile 0
14:36:05.788 INFO  TaskSetManager - Starting task 0.0 in stage 1239.0 (TID 1059) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:36:05.788 INFO  Executor - Running task 0.0 in stage 1239.0 (TID 1059)
14:36:05.791 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
14:36:05.791 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:36:05.793 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:36:05.793 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:36:05.793 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:36:05.799 INFO  FileOutputCommitter - Saved output of task 'attempt_202506021436057970687418468061922_5478_m_000000_0' to file:/tmp/MarkDups3284705873328772189/MarkDups.sam.parts/_temporary/0/task_202506021436057970687418468061922_5478_m_000000
14:36:05.799 INFO  SparkHadoopMapRedUtil - attempt_202506021436057970687418468061922_5478_m_000000_0: Committed. Elapsed time: 0 ms.
14:36:05.799 INFO  Executor - Finished task 0.0 in stage 1239.0 (TID 1059). 1858 bytes result sent to driver
14:36:05.799 INFO  TaskSetManager - Finished task 0.0 in stage 1239.0 (TID 1059) in 11 ms on localhost (executor driver) (1/1)
14:36:05.799 INFO  TaskSchedulerImpl - Removed TaskSet 1239.0, whose tasks have all completed, from pool 
14:36:05.799 INFO  DAGScheduler - ResultStage 1239 (runJob at SparkHadoopWriter.scala:83) finished in 0.019 s
14:36:05.800 INFO  DAGScheduler - Job 557 is finished. Cancelling potential speculative or zombie tasks for this job
14:36:05.800 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1239: Stage finished
14:36:05.800 INFO  DAGScheduler - Job 557 finished: runJob at SparkHadoopWriter.scala:83, took 0.027498 s
14:36:05.800 INFO  SparkHadoopWriter - Start to commit write Job job_202506021436057970687418468061922_5478.
14:36:05.803 INFO  SparkHadoopWriter - Write Job job_202506021436057970687418468061922_5478 committed. Elapsed time: 2 ms.
14:36:05.806 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups3284705873328772189/MarkDups.sam
14:36:05.809 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups3284705873328772189/MarkDups.sam done
14:36:05.809 INFO  MarkDuplicatesSpark - Shutting down engine
[June 2, 2025 at 2:36:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
14:36:11.684 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-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-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-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-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) [?:?]
14:36:11.698 ERROR TaskSetManager - Task 0 in stage 1459.0 failed 1 times; aborting job
[June 2, 2025 at 2:36:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
14:36:11.935 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-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-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-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-5749ecb-SNAPSHOT-local.jar:5749ecb-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) [?:?]
14:36:11.937 ERROR TaskSetManager - Task 0 in stage 1466.0 failed 1 times; aborting job
[June 2, 2025 at 2:36:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216
[June 2, 2025 at 2:36:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1065353216