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

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

152

tests

failures

ignored

59.760s

duration

100%

successful

Tests
Standard error

Tests

Test	Duration	Result
assertThatExpectedOutputUpdateToggleIsDisabled	0s	passed
testAssertAssumeUnsortedFilesAreQueryGroupedFiles	0.559s	passed
testAssertCorrectSortOrderMultipleBams	0.126s	passed
testAssertCorrectSortOrderMultipleBamsOverriding	0.508s	passed
testBulkFragmentsNoDuplicates	0.889s	passed
testBulkFragmentsWithDuplicates	2.036s	passed
testDifferentChromosomesInOppositeOrder	0.322s	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.281s	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.250s	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.278s	passed
testFlowModeFlag	1.716s	passed
testHashCollisionHandling	1.022s	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.296s	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.295s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[0](true, true, true)	0.295s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[1](true, false, true)	0.307s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[2](false, true, true)	0.310s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[3](true, true, false)	0.302s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[4](true, false, false)	0.294s	passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[5](false, true, false)	0.298s	passed
testMappedFragmentAndMappedPairFirstOfPairNonPrimary	0.300s	passed
testMappedFragmentAndMatePairFirstUnmapped	0.293s	passed
testMappedFragmentAndMatePairSecondUnmapped	0.315s	passed
testMappedPairAndMappedFragmentAndMatePairFirstUnmapped	0.306s	passed
testMappedPairAndMappedFragmentAndMatePairSecondUnmapped	0.323s	passed
testMappedPairAndMatePairFirstOppositeStrandSecondUnmapped	0.301s	passed
testMappedPairAndMatePairFirstUnmapped	0.294s	passed
testMappedPairAndMatePairSecondUnmapped	0.292s	passed
testMappedPairWithFirstEndSamePositionAndOther	0.305s	passed
testMappedPairWithSamePosition	0.291s	passed
testMappedPairWithSamePositionSameCigar	0.291s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[0]([Ljava.io.File;@4ad4651c, 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.375s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[1]([Ljava.io.File;@7fafc9ad, 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.388s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[2]([Ljava.io.File;@716b5020, 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.395s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[3]([Ljava.io.File;@5ad6f246, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.324s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[4]([Ljava.io.File;@1c224be5, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.356s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[5]([Ljava.io.File;@329b57dc, 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.229s	passed
testMarkDuplicatesSparkDeletingDuplicateReads[6]([Ljava.io.File;@3c0941db, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.158s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[0]([Ljava.io.File;@70761ca5, 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.358s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[1]([Ljava.io.File;@175baa5b, 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.373s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[2]([Ljava.io.File;@6f28cfb2, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.374s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[3]([Ljava.io.File;@3503092f, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.331s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[4]([Ljava.io.File;@36df5892, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.339s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[5]([Ljava.io.File;@4bd9e302, 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.198s	passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[6]([Ljava.io.File;@3f6c6a51, 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.189s	passed
testMarkDuplicatesSparkIntegrationTestLocal[0]([Ljava.io.File;@326c4257, 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.348s	passed
testMarkDuplicatesSparkIntegrationTestLocal[1]([Ljava.io.File;@1aae8ba4, 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.351s	passed
testMarkDuplicatesSparkIntegrationTestLocal[2]([Ljava.io.File;@75e3de81, 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.351s	passed
testMarkDuplicatesSparkIntegrationTestLocal[3]([Ljava.io.File;@140e6185, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.334s	passed
testMarkDuplicatesSparkIntegrationTestLocal[4]([Ljava.io.File;@5ff9d882, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.330s	passed
testMarkDuplicatesSparkIntegrationTestLocal[5]([Ljava.io.File;@333cf7a4, 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.152s	passed
testMarkDuplicatesSparkIntegrationTestLocal[6]([Ljava.io.File;@d8a9400, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.169s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[0]([Ljava.io.File;@3b1035b7, 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.333s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[1]([Ljava.io.File;@3133a199, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.346s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[2]([Ljava.io.File;@58346f1, 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.345s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[3]([Ljava.io.File;@3263741a, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.334s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[4]([Ljava.io.File;@5e31418a, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.316s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[5]([Ljava.io.File;@60b7be88, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	1.148s	passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[6]([Ljava.io.File;@4cd8b64, 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[0]([Ljava.io.File;@60060955, 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.346s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[1]([Ljava.io.File;@490725a1, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]})	0.347s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[2]([Ljava.io.File;@7fb0e304, 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.368s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[3]([Ljava.io.File;@6660e5cb, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.336s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[4]([Ljava.io.File;@7353cc5b, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]})	0.318s	passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[5]([Ljava.io.File;@3da46665, 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
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[6]([Ljava.io.File;@713c3bbd, 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
testMatePairFirstUnmapped	0.289s	passed
testMatePairSecondUnmapped	0.314s	passed
testNoReadGroupInRead	0.231s	passed
testNonExistantReadGroupInRead	0.214s	passed
testNullOpticalDuplicates	0.311s	passed
testOpticalDuplicateClusterOneEndSamePositionOneCluster	0.308s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicatesWithinPixelDistance	0.296s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834)	0.319s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756)	0.288s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756)	0.311s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756)	0.299s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756)	0.297s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756)	0.298s	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.294s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756)	0.294s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756)	0.292s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756)	0.310s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756)	0.293s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756)	0.299s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756)	0.295s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756)	0.319s	passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756)	0.299s	passed
testOpticalDuplicateClusterSamePositionOneOpticalDuplicatesWithinPixelDistance	0.298s	passed
testOpticalDuplicateClustersAddingSecondEndFirstSameCoordinate	0.301s	passed
testOpticalDuplicateFinding	0.294s	passed
testOpticalDuplicateFindingPxelDistance	0.292s	passed
testOpticalDuplicatesAndPCRDuplicatesOrientationDifference	0.294s	passed
testOpticalDuplicatesDifferentReadGroups	0.304s	passed
testOpticalDuplicatesTheSameReadGroup	0.300s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834)	0.297s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756)	0.291s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756)	0.295s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756)	0.315s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756)	0.307s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756)	0.297s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144)	0.296s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756)	0.292s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756)	0.309s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756)	0.294s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756)	0.297s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756)	0.304s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756)	0.294s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756)	0.303s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756)	0.295s	passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756)	0.309s	passed
testPathologicalOrderingAtTheSamePosition	0.318s	passed
testReadSameStartPositionOrientationOverride	0.296s	passed
testReadsHaveSameStartPositionButDifferentChromosomeNonEquivalence	0.292s	passed
testSecondEndIsBeforeFirstInCoordinate	0.286s	passed
testSingleMappedFragment	0.307s	passed
testSingleMappedFragmentAndSingleMappedPair	0.295s	passed
testSingleMappedFragmentAndTwoMappedPairs	0.308s	passed
testSingleMappedPair	0.305s	passed
testSingleUnmappedFragment	0.287s	passed
testSingleUnmappedPair	0.286s	passed
testStackOverFlowPairSetSwap	0.299s	passed
testSupplementaryReadUnmappedMate	0.313s	passed
testThreeGroupsOnDifferentChromosomesOfThreeMappedPairs	0.296s	passed
testThreeMappedPairs	0.290s	passed
testThreeMappedPairsWithMatchingSecondMate	0.303s	passed
testTwoGroupsOnDifferentChromosomesOfThreeMappedPairs	0.293s	passed
testTwoGroupsOnDifferentChromosomesOfTwoFragments	0.291s	passed
testTwoGroupsOnDifferentChromosomesOfTwoMappedPairs	0.303s	passed
testTwoMappedFragments	0.306s	passed
testTwoMappedPairWithSamePosition	0.298s	passed
testTwoMappedPairWithSamePositionDifferentStrands	0.299s	passed
testTwoMappedPairWithSamePositionDifferentStrands2	0.290s	passed
testTwoMappedPairs	0.302s	passed
testTwoMappedPairsAndMappedSecondaryFragment	0.293s	passed
testTwoMappedPairsAndTerminalUnmappedFragment	0.296s	passed
testTwoMappedPairsAndTerminalUnmappedPair	0.309s	passed
testTwoMappedPairsMatesSoftClipped	0.288s	passed
testTwoMappedPairsWithOppositeOrientations	0.310s	passed
testTwoMappedPairsWithOppositeOrientationsNumberTwo	0.299s	passed
testTwoMappedPairsWithSoftClipping	0.306s	passed
testTwoMappedPairsWithSoftClippingBoth	0.297s	passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnly	0.288s	passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnlyNoMateCigar	0.304s	passed
testTwoMappedPairsWithSupplementaryReads[0](true, true, true)	0.290s	passed
testTwoMappedPairsWithSupplementaryReads[1](true, false, true)	0.292s	passed
testTwoMappedPairsWithSupplementaryReads[2](false, true, true)	0.289s	passed
testTwoMappedPairsWithSupplementaryReads[3](true, true, false)	0.304s	passed
testTwoMappedPairsWithSupplementaryReads[4](true, false, false)	0.295s	passed
testTwoMappedPairsWithSupplementaryReads[5](false, true, false)	0.292s	passed
testTwoUnmappedFragments	0.301s	passed

Standard error

[May 27, 2025 at 2:57:35 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:35 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:35 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:37 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:38 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
14:57:38.626 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:57:38.626 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
14:57:38.626 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:57:38.626 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:57:38.626 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:57:38.626 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:57:38 PM UTC
14:57:38.626 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:57:38.626 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:57:38.627 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:57:38.627 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:57:38.627 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:57:38.627 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:57:38.627 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:57:38.627 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:57:38.627 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:57:38.627 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:57:38.627 INFO  MarkDuplicatesSpark - Initializing engine
14:57:38.627 INFO  MarkDuplicatesSpark - Done initializing engine
14:57:38.627 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:57:38.630 INFO  MemoryStore - Block broadcast_1371 stored as values in memory (estimated size 306.3 KiB, free 1903.1 MiB)
14:57:38.636 INFO  MemoryStore - Block broadcast_1371_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1903.0 MiB)
14:57:38.637 INFO  BlockManagerInfo - Added broadcast_1371_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.9 MiB)
14:57:38.637 INFO  SparkContext - Created broadcast 1371 from newAPIHadoopFile at PathSplitSource.java:96
14:57:38.657 INFO  MemoryStore - Block broadcast_1372 stored as values in memory (estimated size 306.3 KiB, free 1902.7 MiB)
14:57:38.664 INFO  MemoryStore - Block broadcast_1372_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1902.7 MiB)
14:57:38.664 INFO  BlockManagerInfo - Added broadcast_1372_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.8 MiB)
14:57:38.664 INFO  SparkContext - Created broadcast 1372 from newAPIHadoopFile at PathSplitSource.java:96
14:57:38.697 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:57:38.698 INFO  FileInputFormat - Total input files to process : 1
14:57:38.698 INFO  DAGScheduler - Registering RDD 3483 (mapToPair at SparkUtils.java:161) as input to shuffle 100
14:57:38.699 INFO  DAGScheduler - Got job 423 (collect at SparkUtils.java:205) with 1 output partitions
14:57:38.699 INFO  DAGScheduler - Final stage: ResultStage 735 (collect at SparkUtils.java:205)
14:57:38.699 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 734)
14:57:38.699 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 734)
14:57:38.699 INFO  DAGScheduler - Submitting ShuffleMapStage 734 (MapPartitionsRDD[3483] at mapToPair at SparkUtils.java:161), which has no missing parents
14:57:38.716 INFO  MemoryStore - Block broadcast_1373 stored as values in memory (estimated size 460.4 KiB, free 1902.2 MiB)
14:57:38.719 INFO  MemoryStore - Block broadcast_1373_piece0 stored as bytes in memory (estimated size 202.5 KiB, free 1902.0 MiB)
14:57:38.719 INFO  BlockManagerInfo - Added broadcast_1373_piece0 in memory on localhost:35475 (size: 202.5 KiB, free: 1918.6 MiB)
14:57:38.719 INFO  SparkContext - Created broadcast 1373 from broadcast at DAGScheduler.scala:1580
14:57:38.719 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 734 (MapPartitionsRDD[3483] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:57:38.719 INFO  TaskSchedulerImpl - Adding task set 734.0 with 1 tasks resource profile 0
14:57:38.720 INFO  TaskSetManager - Starting task 0.0 in stage 734.0 (TID 676) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9735 bytes) 
14:57:38.721 INFO  Executor - Running task 0.0 in stage 734.0 (TID 676)
14:57:38.750 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam:0+1507
14:57:38.755 INFO  Executor - Finished task 0.0 in stage 734.0 (TID 676). 1148 bytes result sent to driver
14:57:38.755 INFO  TaskSetManager - Finished task 0.0 in stage 734.0 (TID 676) in 35 ms on localhost (executor driver) (1/1)
14:57:38.755 INFO  TaskSchedulerImpl - Removed TaskSet 734.0, whose tasks have all completed, from pool 
14:57:38.755 INFO  DAGScheduler - ShuffleMapStage 734 (mapToPair at SparkUtils.java:161) finished in 0.055 s
14:57:38.755 INFO  DAGScheduler - looking for newly runnable stages
14:57:38.755 INFO  DAGScheduler - running: HashSet()
14:57:38.755 INFO  DAGScheduler - waiting: HashSet(ResultStage 735)
14:57:38.755 INFO  DAGScheduler - failed: HashSet()
14:57:38.756 INFO  DAGScheduler - Submitting ResultStage 735 (MapPartitionsRDD[3486] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:57:38.756 INFO  MemoryStore - Block broadcast_1374 stored as values in memory (estimated size 7.4 KiB, free 1902.0 MiB)
14:57:38.757 INFO  MemoryStore - Block broadcast_1374_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1902.0 MiB)
14:57:38.757 INFO  BlockManagerInfo - Added broadcast_1374_piece0 in memory on localhost:35475 (size: 4.1 KiB, free: 1918.6 MiB)
14:57:38.757 INFO  SparkContext - Created broadcast 1374 from broadcast at DAGScheduler.scala:1580
14:57:38.757 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 735 (MapPartitionsRDD[3486] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:57:38.757 INFO  TaskSchedulerImpl - Adding task set 735.0 with 1 tasks resource profile 0
14:57:38.758 INFO  TaskSetManager - Starting task 0.0 in stage 735.0 (TID 677) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:57:38.758 INFO  Executor - Running task 0.0 in stage 735.0 (TID 677)
14:57:38.759 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:57:38.759 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.761 INFO  Executor - Finished task 0.0 in stage 735.0 (TID 677). 2238 bytes result sent to driver
14:57:38.761 INFO  TaskSetManager - Finished task 0.0 in stage 735.0 (TID 677) in 3 ms on localhost (executor driver) (1/1)
14:57:38.761 INFO  TaskSchedulerImpl - Removed TaskSet 735.0, whose tasks have all completed, from pool 
14:57:38.761 INFO  DAGScheduler - ResultStage 735 (collect at SparkUtils.java:205) finished in 0.005 s
14:57:38.761 INFO  DAGScheduler - Job 423 is finished. Cancelling potential speculative or zombie tasks for this job
14:57:38.762 INFO  TaskSchedulerImpl - Killing all running tasks in stage 735: Stage finished
14:57:38.762 INFO  DAGScheduler - Job 423 finished: collect at SparkUtils.java:205, took 0.064497 s
14:57:38.766 INFO  MemoryStore - Block broadcast_1375 stored as values in memory (estimated size 1632.0 B, free 1902.0 MiB)
14:57:38.767 INFO  MemoryStore - Block broadcast_1375_piece0 stored as bytes in memory (estimated size 145.0 B, free 1902.0 MiB)
14:57:38.767 INFO  BlockManagerInfo - Added broadcast_1375_piece0 in memory on localhost:35475 (size: 145.0 B, free: 1918.6 MiB)
14:57:38.767 INFO  SparkContext - Created broadcast 1375 from broadcast at MarkDuplicatesSparkUtils.java:126
14:57:38.767 INFO  MemoryStore - Block broadcast_1376 stored as values in memory (estimated size 304.0 B, free 1902.0 MiB)
14:57:38.767 INFO  MemoryStore - Block broadcast_1376_piece0 stored as bytes in memory (estimated size 37.0 B, free 1902.0 MiB)
14:57:38.768 INFO  BlockManagerInfo - Added broadcast_1376_piece0 in memory on localhost:35475 (size: 37.0 B, free: 1918.6 MiB)
14:57:38.768 INFO  SparkContext - Created broadcast 1376 from broadcast at MarkDuplicatesSparkUtils.java:127
14:57:38.780 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:57:38.780 INFO  DAGScheduler - Registering RDD 3495 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 103
14:57:38.780 INFO  DAGScheduler - Registering RDD 3499 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 102
14:57:38.781 INFO  DAGScheduler - Registering RDD 3503 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 101
14:57:38.781 INFO  DAGScheduler - Got job 424 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:57:38.781 INFO  DAGScheduler - Final stage: ResultStage 740 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:57:38.781 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 739)
14:57:38.781 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 739)
14:57:38.781 INFO  DAGScheduler - Submitting ShuffleMapStage 737 (MapPartitionsRDD[3495] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:57:38.782 INFO  MemoryStore - Block broadcast_1377 stored as values in memory (estimated size 24.2 KiB, free 1902.0 MiB)
14:57:38.782 INFO  MemoryStore - Block broadcast_1377_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1902.0 MiB)
14:57:38.783 INFO  BlockManagerInfo - Added broadcast_1377_piece0 in memory on localhost:35475 (size: 12.6 KiB, free: 1918.6 MiB)
14:57:38.783 INFO  SparkContext - Created broadcast 1377 from broadcast at DAGScheduler.scala:1580
14:57:38.783 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 737 (MapPartitionsRDD[3495] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:57:38.783 INFO  TaskSchedulerImpl - Adding task set 737.0 with 1 tasks resource profile 0
14:57:38.784 INFO  TaskSetManager - Starting task 0.0 in stage 737.0 (TID 678) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
14:57:38.784 INFO  Executor - Running task 0.0 in stage 737.0 (TID 678)
14:57:38.786 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:57:38.786 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.789 INFO  Executor - Finished task 0.0 in stage 737.0 (TID 678). 1922 bytes result sent to driver
14:57:38.789 INFO  TaskSetManager - Finished task 0.0 in stage 737.0 (TID 678) in 6 ms on localhost (executor driver) (1/1)
14:57:38.789 INFO  TaskSchedulerImpl - Removed TaskSet 737.0, whose tasks have all completed, from pool 
14:57:38.789 INFO  DAGScheduler - ShuffleMapStage 737 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
14:57:38.789 INFO  DAGScheduler - looking for newly runnable stages
14:57:38.789 INFO  DAGScheduler - running: HashSet()
14:57:38.789 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 738, ShuffleMapStage 739, ResultStage 740)
14:57:38.789 INFO  DAGScheduler - failed: HashSet()
14:57:38.790 INFO  DAGScheduler - Submitting ShuffleMapStage 738 (MapPartitionsRDD[3499] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:57:38.790 INFO  MemoryStore - Block broadcast_1378 stored as values in memory (estimated size 28.3 KiB, free 1902.0 MiB)
14:57:38.791 INFO  MemoryStore - Block broadcast_1378_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1901.9 MiB)
14:57:38.791 INFO  BlockManagerInfo - Added broadcast_1378_piece0 in memory on localhost:35475 (size: 14.8 KiB, free: 1918.6 MiB)
14:57:38.791 INFO  SparkContext - Created broadcast 1378 from broadcast at DAGScheduler.scala:1580
14:57:38.791 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 738 (MapPartitionsRDD[3499] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:57:38.791 INFO  TaskSchedulerImpl - Adding task set 738.0 with 1 tasks resource profile 0
14:57:38.792 INFO  TaskSetManager - Starting task 0.0 in stage 738.0 (TID 679) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
14:57:38.792 INFO  Executor - Running task 0.0 in stage 738.0 (TID 679)
14:57:38.794 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:57:38.794 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.797 INFO  Executor - Finished task 0.0 in stage 738.0 (TID 679). 1922 bytes result sent to driver
14:57:38.798 INFO  TaskSetManager - Finished task 0.0 in stage 738.0 (TID 679) in 6 ms on localhost (executor driver) (1/1)
14:57:38.798 INFO  TaskSchedulerImpl - Removed TaskSet 738.0, whose tasks have all completed, from pool 
14:57:38.798 INFO  DAGScheduler - ShuffleMapStage 738 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.008 s
14:57:38.798 INFO  DAGScheduler - looking for newly runnable stages
14:57:38.798 INFO  DAGScheduler - running: HashSet()
14:57:38.798 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 739, ResultStage 740)
14:57:38.798 INFO  DAGScheduler - failed: HashSet()
14:57:38.798 INFO  DAGScheduler - Submitting ShuffleMapStage 739 (MapPartitionsRDD[3503] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:57:38.799 INFO  MemoryStore - Block broadcast_1379 stored as values in memory (estimated size 19.0 KiB, free 1901.9 MiB)
14:57:38.800 INFO  MemoryStore - Block broadcast_1379_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1901.9 MiB)
14:57:38.800 INFO  BlockManagerInfo - Added broadcast_1379_piece0 in memory on localhost:35475 (size: 9.7 KiB, free: 1918.6 MiB)
14:57:38.800 INFO  SparkContext - Created broadcast 1379 from broadcast at DAGScheduler.scala:1580
14:57:38.800 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 739 (MapPartitionsRDD[3503] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:57:38.800 INFO  TaskSchedulerImpl - Adding task set 739.0 with 1 tasks resource profile 0
14:57:38.801 INFO  TaskSetManager - Starting task 0.0 in stage 739.0 (TID 680) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:57:38.801 INFO  Executor - Running task 0.0 in stage 739.0 (TID 680)
14:57:38.803 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:57:38.803 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.805 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:57:38.805 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.806 INFO  Executor - Finished task 0.0 in stage 739.0 (TID 680). 1922 bytes result sent to driver
14:57:38.806 INFO  TaskSetManager - Finished task 0.0 in stage 739.0 (TID 680) in 5 ms on localhost (executor driver) (1/1)
14:57:38.806 INFO  TaskSchedulerImpl - Removed TaskSet 739.0, whose tasks have all completed, from pool 
14:57:38.807 INFO  DAGScheduler - ShuffleMapStage 739 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
14:57:38.807 INFO  DAGScheduler - looking for newly runnable stages
14:57:38.807 INFO  DAGScheduler - running: HashSet()
14:57:38.807 INFO  DAGScheduler - waiting: HashSet(ResultStage 740)
14:57:38.807 INFO  DAGScheduler - failed: HashSet()
14:57:38.807 INFO  DAGScheduler - Submitting ResultStage 740 (MapPartitionsRDD[3505] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:57:38.808 INFO  MemoryStore - Block broadcast_1380 stored as values in memory (estimated size 20.2 KiB, free 1901.9 MiB)
14:57:38.808 INFO  MemoryStore - Block broadcast_1380_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1901.9 MiB)
14:57:38.808 INFO  BlockManagerInfo - Added broadcast_1380_piece0 in memory on localhost:35475 (size: 10.6 KiB, free: 1918.5 MiB)
14:57:38.809 INFO  SparkContext - Created broadcast 1380 from broadcast at DAGScheduler.scala:1580
14:57:38.809 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 740 (MapPartitionsRDD[3505] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:57:38.809 INFO  TaskSchedulerImpl - Adding task set 740.0 with 1 tasks resource profile 0
14:57:38.809 INFO  TaskSetManager - Starting task 0.0 in stage 740.0 (TID 681) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:57:38.810 INFO  Executor - Running task 0.0 in stage 740.0 (TID 681)
14:57:38.811 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:57:38.811 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.813 INFO  Executor - Finished task 0.0 in stage 740.0 (TID 681). 1901 bytes result sent to driver
14:57:38.813 INFO  TaskSetManager - Finished task 0.0 in stage 740.0 (TID 681) in 4 ms on localhost (executor driver) (1/1)
14:57:38.813 INFO  TaskSchedulerImpl - Removed TaskSet 740.0, whose tasks have all completed, from pool 
14:57:38.813 INFO  DAGScheduler - ResultStage 740 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.006 s
14:57:38.813 INFO  DAGScheduler - Job 424 is finished. Cancelling potential speculative or zombie tasks for this job
14:57:38.813 INFO  TaskSchedulerImpl - Killing all running tasks in stage 740: Stage finished
14:57:38.813 INFO  DAGScheduler - Job 424 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.033590 s
14:57:38.824 INFO  MemoryStore - Block broadcast_1381 stored as values in memory (estimated size 20.3 KiB, free 1901.9 MiB)
14:57:38.824 INFO  MemoryStore - Block broadcast_1381_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1901.9 MiB)
14:57:38.825 INFO  BlockManagerInfo - Added broadcast_1381_piece0 in memory on localhost:35475 (size: 1850.0 B, free: 1918.5 MiB)
14:57:38.825 INFO  SparkContext - Created broadcast 1381 from broadcast at ReadsSparkSink.java:133
14:57:38.826 INFO  MemoryStore - Block broadcast_1382 stored as values in memory (estimated size 20.4 KiB, free 1901.8 MiB)
14:57:38.826 INFO  MemoryStore - Block broadcast_1382_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1901.8 MiB)
14:57:38.826 INFO  BlockManagerInfo - Added broadcast_1382_piece0 in memory on localhost:35475 (size: 1850.0 B, free: 1918.5 MiB)
14:57:38.826 INFO  SparkContext - Created broadcast 1382 from broadcast at BamSink.java:76
14:57:38.828 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:57:38.828 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:57:38.828 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:57:38.844 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:57:38.845 INFO  DAGScheduler - Registering RDD 3507 (mapToPair at SparkUtils.java:161) as input to shuffle 104
14:57:38.845 INFO  DAGScheduler - Got job 425 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:57:38.845 INFO  DAGScheduler - Final stage: ResultStage 745 (runJob at SparkHadoopWriter.scala:83)
14:57:38.845 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 744)
14:57:38.845 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 744)
14:57:38.845 INFO  DAGScheduler - Submitting ShuffleMapStage 744 (MapPartitionsRDD[3507] at mapToPair at SparkUtils.java:161), which has no missing parents
14:57:38.846 INFO  MemoryStore - Block broadcast_1383 stored as values in memory (estimated size 18.1 KiB, free 1901.8 MiB)
14:57:38.847 INFO  MemoryStore - Block broadcast_1383_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1901.8 MiB)
14:57:38.847 INFO  BlockManagerInfo - Added broadcast_1383_piece0 in memory on localhost:35475 (size: 9.5 KiB, free: 1918.5 MiB)
14:57:38.847 INFO  SparkContext - Created broadcast 1383 from broadcast at DAGScheduler.scala:1580
14:57:38.847 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 744 (MapPartitionsRDD[3507] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:57:38.848 INFO  TaskSchedulerImpl - Adding task set 744.0 with 1 tasks resource profile 0
14:57:38.848 INFO  TaskSetManager - Starting task 0.0 in stage 744.0 (TID 682) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:57:38.848 INFO  Executor - Running task 0.0 in stage 744.0 (TID 682)
14:57:38.850 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:57:38.850 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.852 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:57:38.852 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.853 INFO  Executor - Finished task 0.0 in stage 744.0 (TID 682). 1922 bytes result sent to driver
14:57:38.853 INFO  TaskSetManager - Finished task 0.0 in stage 744.0 (TID 682) in 5 ms on localhost (executor driver) (1/1)
14:57:38.854 INFO  TaskSchedulerImpl - Removed TaskSet 744.0, whose tasks have all completed, from pool 
14:57:38.854 INFO  DAGScheduler - ShuffleMapStage 744 (mapToPair at SparkUtils.java:161) finished in 0.008 s
14:57:38.854 INFO  DAGScheduler - looking for newly runnable stages
14:57:38.854 INFO  DAGScheduler - running: HashSet()
14:57:38.854 INFO  DAGScheduler - waiting: HashSet(ResultStage 745)
14:57:38.854 INFO  DAGScheduler - failed: HashSet()
14:57:38.854 INFO  DAGScheduler - Submitting ResultStage 745 (MapPartitionsRDD[3512] at mapToPair at BamSink.java:91), which has no missing parents
14:57:38.860 INFO  MemoryStore - Block broadcast_1384 stored as values in memory (estimated size 163.7 KiB, free 1901.6 MiB)
14:57:38.861 INFO  MemoryStore - Block broadcast_1384_piece0 stored as bytes in memory (estimated size 73.9 KiB, free 1901.6 MiB)
14:57:38.861 INFO  BlockManagerInfo - Added broadcast_1384_piece0 in memory on localhost:35475 (size: 73.9 KiB, free: 1918.5 MiB)
14:57:38.862 INFO  SparkContext - Created broadcast 1384 from broadcast at DAGScheduler.scala:1580
14:57:38.862 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 745 (MapPartitionsRDD[3512] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
14:57:38.862 INFO  TaskSchedulerImpl - Adding task set 745.0 with 1 tasks resource profile 0
14:57:38.862 INFO  TaskSetManager - Starting task 0.0 in stage 745.0 (TID 683) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:57:38.862 INFO  Executor - Running task 0.0 in stage 745.0 (TID 683)
14:57:38.866 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:57:38.866 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:38.868 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:57:38.868 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:57:38.868 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:57:38.868 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:57:38.868 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:57:38.868 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:57:38.886 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271457387705736463933100199_3512_r_000000_0' to file:/tmp/local111378223953060423084/markdups15902533880085121464.bam.parts/_temporary/0/task_202505271457387705736463933100199_3512_r_000000
14:57:38.887 INFO  SparkHadoopMapRedUtil - attempt_202505271457387705736463933100199_3512_r_000000_0: Committed. Elapsed time: 0 ms.
14:57:38.887 INFO  Executor - Finished task 0.0 in stage 745.0 (TID 683). 1858 bytes result sent to driver
14:57:38.887 INFO  TaskSetManager - Finished task 0.0 in stage 745.0 (TID 683) in 25 ms on localhost (executor driver) (1/1)
14:57:38.887 INFO  TaskSchedulerImpl - Removed TaskSet 745.0, whose tasks have all completed, from pool 
14:57:38.888 INFO  DAGScheduler - ResultStage 745 (runJob at SparkHadoopWriter.scala:83) finished in 0.033 s
14:57:38.888 INFO  DAGScheduler - Job 425 is finished. Cancelling potential speculative or zombie tasks for this job
14:57:38.888 INFO  TaskSchedulerImpl - Killing all running tasks in stage 745: Stage finished
14:57:38.888 INFO  DAGScheduler - Job 425 finished: runJob at SparkHadoopWriter.scala:83, took 0.043308 s
14:57:38.888 INFO  SparkHadoopWriter - Start to commit write Job job_202505271457387705736463933100199_3512.
14:57:38.892 INFO  SparkHadoopWriter - Write Job job_202505271457387705736463933100199_3512 committed. Elapsed time: 4 ms.
14:57:38.903 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local111378223953060423084/markdups15902533880085121464.bam
14:57:38.907 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local111378223953060423084/markdups15902533880085121464.bam done
14:57:38.907 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local111378223953060423084/markdups15902533880085121464.bam.parts/ to /tmp/local111378223953060423084/markdups15902533880085121464.bam.sbi
14:57:38.911 INFO  IndexFileMerger - Done merging .sbi files
14:57:38.911 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local111378223953060423084/markdups15902533880085121464.bam.parts/ to /tmp/local111378223953060423084/markdups15902533880085121464.bam.bai
14:57:38.915 INFO  IndexFileMerger - Done merging .bai files
14:57:38.916 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:57:38 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
14:57:38.923 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:57:38.923 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
14:57:38.923 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:57:38.923 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:57:38.923 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:57:38.923 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:57:38 PM UTC
14:57:38.923 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:57:38.923 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:57:38.923 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:57:38.923 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:57:38.923 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:57:38.923 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:57:38.923 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:57:38.923 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:57:38.923 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:57:38.924 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:57:38.924 INFO  MarkDuplicatesSpark - Initializing engine
14:57:38.924 INFO  MarkDuplicatesSpark - Done initializing engine
14:57:38.924 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:57:38.926 INFO  MemoryStore - Block broadcast_1385 stored as values in memory (estimated size 306.3 KiB, free 1901.3 MiB)
14:57:38.932 INFO  MemoryStore - Block broadcast_1385_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1901.2 MiB)
14:57:38.933 INFO  BlockManagerInfo - Added broadcast_1385_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.4 MiB)
14:57:38.933 INFO  SparkContext - Created broadcast 1385 from newAPIHadoopFile at PathSplitSource.java:96
14:57:38.952 INFO  MemoryStore - Block broadcast_1386 stored as values in memory (estimated size 306.3 KiB, free 1900.9 MiB)
14:57:38.959 INFO  MemoryStore - Block broadcast_1386_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1900.9 MiB)
14:57:38.959 INFO  BlockManagerInfo - Added broadcast_1386_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.3 MiB)
14:57:38.959 INFO  SparkContext - Created broadcast 1386 from newAPIHadoopFile at PathSplitSource.java:96
14:57:38.991 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:57:38.992 INFO  FileInputFormat - Total input files to process : 1
14:57:38.992 INFO  DAGScheduler - Registering RDD 3526 (mapToPair at SparkUtils.java:161) as input to shuffle 105
14:57:38.992 INFO  DAGScheduler - Got job 426 (collect at SparkUtils.java:205) with 1 output partitions
14:57:38.992 INFO  DAGScheduler - Final stage: ResultStage 747 (collect at SparkUtils.java:205)
14:57:38.992 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 746)
14:57:38.992 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 746)
14:57:38.992 INFO  DAGScheduler - Submitting ShuffleMapStage 746 (MapPartitionsRDD[3526] at mapToPair at SparkUtils.java:161), which has no missing parents
14:57:39.009 INFO  MemoryStore - Block broadcast_1387 stored as values in memory (estimated size 460.4 KiB, free 1900.4 MiB)
14:57:39.011 INFO  MemoryStore - Block broadcast_1387_piece0 stored as bytes in memory (estimated size 202.5 KiB, free 1900.2 MiB)
14:57:39.012 INFO  BlockManagerInfo - Added broadcast_1387_piece0 in memory on localhost:35475 (size: 202.5 KiB, free: 1918.1 MiB)
14:57:39.012 INFO  SparkContext - Created broadcast 1387 from broadcast at DAGScheduler.scala:1580
14:57:39.012 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 746 (MapPartitionsRDD[3526] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:57:39.012 INFO  TaskSchedulerImpl - Adding task set 746.0 with 1 tasks resource profile 0
14:57:39.012 INFO  TaskSetManager - Starting task 0.0 in stage 746.0 (TID 684) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9736 bytes) 
14:57:39.013 INFO  Executor - Running task 0.0 in stage 746.0 (TID 684)
14:57:39.042 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam:0+1856
14:57:39.046 INFO  Executor - Finished task 0.0 in stage 746.0 (TID 684). 1148 bytes result sent to driver
14:57:39.046 INFO  TaskSetManager - Finished task 0.0 in stage 746.0 (TID 684) in 34 ms on localhost (executor driver) (1/1)
14:57:39.046 INFO  TaskSchedulerImpl - Removed TaskSet 746.0, whose tasks have all completed, from pool 
14:57:39.046 INFO  DAGScheduler - ShuffleMapStage 746 (mapToPair at SparkUtils.java:161) finished in 0.053 s
14:57:39.046 INFO  DAGScheduler - looking for newly runnable stages
14:57:39.047 INFO  DAGScheduler - running: HashSet()
14:57:39.047 INFO  DAGScheduler - waiting: HashSet(ResultStage 747)
14:57:39.047 INFO  DAGScheduler - failed: HashSet()
14:57:39.047 INFO  DAGScheduler - Submitting ResultStage 747 (MapPartitionsRDD[3529] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:57:39.047 INFO  MemoryStore - Block broadcast_1388 stored as values in memory (estimated size 7.4 KiB, free 1900.2 MiB)
14:57:39.048 INFO  MemoryStore - Block broadcast_1388_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1900.2 MiB)
14:57:39.048 INFO  BlockManagerInfo - Added broadcast_1388_piece0 in memory on localhost:35475 (size: 4.1 KiB, free: 1918.1 MiB)
14:57:39.048 INFO  SparkContext - Created broadcast 1388 from broadcast at DAGScheduler.scala:1580
14:57:39.048 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 747 (MapPartitionsRDD[3529] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:57:39.048 INFO  TaskSchedulerImpl - Adding task set 747.0 with 1 tasks resource profile 0
14:57:39.049 INFO  TaskSetManager - Starting task 0.0 in stage 747.0 (TID 685) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:57:39.049 INFO  Executor - Running task 0.0 in stage 747.0 (TID 685)
14:57:39.050 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:57:39.050 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.051 INFO  Executor - Finished task 0.0 in stage 747.0 (TID 685). 2495 bytes result sent to driver
14:57:39.052 INFO  TaskSetManager - Finished task 0.0 in stage 747.0 (TID 685) in 4 ms on localhost (executor driver) (1/1)
14:57:39.052 INFO  TaskSchedulerImpl - Removed TaskSet 747.0, whose tasks have all completed, from pool 
14:57:39.052 INFO  DAGScheduler - ResultStage 747 (collect at SparkUtils.java:205) finished in 0.005 s
14:57:39.052 INFO  DAGScheduler - Job 426 is finished. Cancelling potential speculative or zombie tasks for this job
14:57:39.052 INFO  TaskSchedulerImpl - Killing all running tasks in stage 747: Stage finished
14:57:39.052 INFO  DAGScheduler - Job 426 finished: collect at SparkUtils.java:205, took 0.060934 s
14:57:39.056 INFO  MemoryStore - Block broadcast_1389 stored as values in memory (estimated size 1632.0 B, free 1900.2 MiB)
14:57:39.057 INFO  MemoryStore - Block broadcast_1389_piece0 stored as bytes in memory (estimated size 145.0 B, free 1900.2 MiB)
14:57:39.057 INFO  BlockManagerInfo - Added broadcast_1389_piece0 in memory on localhost:35475 (size: 145.0 B, free: 1918.1 MiB)
14:57:39.057 INFO  SparkContext - Created broadcast 1389 from broadcast at MarkDuplicatesSparkUtils.java:126
14:57:39.057 INFO  MemoryStore - Block broadcast_1390 stored as values in memory (estimated size 304.0 B, free 1900.2 MiB)
14:57:39.058 INFO  MemoryStore - Block broadcast_1390_piece0 stored as bytes in memory (estimated size 37.0 B, free 1900.2 MiB)
14:57:39.058 INFO  BlockManagerInfo - Added broadcast_1390_piece0 in memory on localhost:35475 (size: 37.0 B, free: 1918.1 MiB)
14:57:39.058 INFO  SparkContext - Created broadcast 1390 from broadcast at MarkDuplicatesSparkUtils.java:127
14:57:39.070 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:57:39.071 INFO  DAGScheduler - Registering RDD 3538 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 108
14:57:39.071 INFO  DAGScheduler - Registering RDD 3542 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 107
14:57:39.071 INFO  DAGScheduler - Registering RDD 3546 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 106
14:57:39.071 INFO  DAGScheduler - Got job 427 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:57:39.071 INFO  DAGScheduler - Final stage: ResultStage 752 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:57:39.071 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 751)
14:57:39.071 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 751)
14:57:39.071 INFO  DAGScheduler - Submitting ShuffleMapStage 749 (MapPartitionsRDD[3538] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:57:39.072 INFO  MemoryStore - Block broadcast_1391 stored as values in memory (estimated size 24.2 KiB, free 1900.2 MiB)
14:57:39.073 INFO  MemoryStore - Block broadcast_1391_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1900.2 MiB)
14:57:39.073 INFO  BlockManagerInfo - Added broadcast_1391_piece0 in memory on localhost:35475 (size: 12.6 KiB, free: 1918.1 MiB)
14:57:39.073 INFO  SparkContext - Created broadcast 1391 from broadcast at DAGScheduler.scala:1580
14:57:39.073 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 749 (MapPartitionsRDD[3538] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:57:39.073 INFO  TaskSchedulerImpl - Adding task set 749.0 with 1 tasks resource profile 0
14:57:39.074 INFO  TaskSetManager - Starting task 0.0 in stage 749.0 (TID 686) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
14:57:39.074 INFO  Executor - Running task 0.0 in stage 749.0 (TID 686)
14:57:39.075 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:57:39.075 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.078 INFO  Executor - Finished task 0.0 in stage 749.0 (TID 686). 1922 bytes result sent to driver
14:57:39.078 INFO  TaskSetManager - Finished task 0.0 in stage 749.0 (TID 686) in 5 ms on localhost (executor driver) (1/1)
14:57:39.078 INFO  TaskSchedulerImpl - Removed TaskSet 749.0, whose tasks have all completed, from pool 
14:57:39.078 INFO  DAGScheduler - ShuffleMapStage 749 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.006 s
14:57:39.078 INFO  DAGScheduler - looking for newly runnable stages
14:57:39.078 INFO  DAGScheduler - running: HashSet()
14:57:39.079 INFO  DAGScheduler - waiting: HashSet(ResultStage 752, ShuffleMapStage 750, ShuffleMapStage 751)
14:57:39.079 INFO  DAGScheduler - failed: HashSet()
14:57:39.079 INFO  DAGScheduler - Submitting ShuffleMapStage 750 (MapPartitionsRDD[3542] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:57:39.079 INFO  MemoryStore - Block broadcast_1392 stored as values in memory (estimated size 28.3 KiB, free 1900.1 MiB)
14:57:39.080 INFO  MemoryStore - Block broadcast_1392_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1900.1 MiB)
14:57:39.080 INFO  BlockManagerInfo - Added broadcast_1392_piece0 in memory on localhost:35475 (size: 14.8 KiB, free: 1918.1 MiB)
14:57:39.080 INFO  SparkContext - Created broadcast 1392 from broadcast at DAGScheduler.scala:1580
14:57:39.080 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 750 (MapPartitionsRDD[3542] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:57:39.080 INFO  TaskSchedulerImpl - Adding task set 750.0 with 1 tasks resource profile 0
14:57:39.081 INFO  TaskSetManager - Starting task 0.0 in stage 750.0 (TID 687) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
14:57:39.081 INFO  Executor - Running task 0.0 in stage 750.0 (TID 687)
14:57:39.082 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:57:39.082 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.086 INFO  Executor - Finished task 0.0 in stage 750.0 (TID 687). 1879 bytes result sent to driver
14:57:39.086 INFO  TaskSetManager - Finished task 0.0 in stage 750.0 (TID 687) in 5 ms on localhost (executor driver) (1/1)
14:57:39.087 INFO  TaskSchedulerImpl - Removed TaskSet 750.0, whose tasks have all completed, from pool 
14:57:39.087 INFO  DAGScheduler - ShuffleMapStage 750 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.008 s
14:57:39.087 INFO  DAGScheduler - looking for newly runnable stages
14:57:39.087 INFO  DAGScheduler - running: HashSet()
14:57:39.087 INFO  DAGScheduler - waiting: HashSet(ResultStage 752, ShuffleMapStage 751)
14:57:39.087 INFO  DAGScheduler - failed: HashSet()
14:57:39.087 INFO  DAGScheduler - Submitting ShuffleMapStage 751 (MapPartitionsRDD[3546] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:57:39.088 INFO  MemoryStore - Block broadcast_1393 stored as values in memory (estimated size 19.0 KiB, free 1900.1 MiB)
14:57:39.088 INFO  MemoryStore - Block broadcast_1393_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1900.1 MiB)
14:57:39.088 INFO  BlockManagerInfo - Added broadcast_1393_piece0 in memory on localhost:35475 (size: 9.7 KiB, free: 1918.1 MiB)
14:57:39.089 INFO  SparkContext - Created broadcast 1393 from broadcast at DAGScheduler.scala:1580
14:57:39.089 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 751 (MapPartitionsRDD[3546] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:57:39.089 INFO  TaskSchedulerImpl - Adding task set 751.0 with 1 tasks resource profile 0
14:57:39.089 INFO  TaskSetManager - Starting task 0.0 in stage 751.0 (TID 688) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:57:39.089 INFO  Executor - Running task 0.0 in stage 751.0 (TID 688)
14:57:39.091 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:57:39.091 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.093 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:57:39.093 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.095 INFO  Executor - Finished task 0.0 in stage 751.0 (TID 688). 1922 bytes result sent to driver
14:57:39.095 INFO  TaskSetManager - Finished task 0.0 in stage 751.0 (TID 688) in 6 ms on localhost (executor driver) (1/1)
14:57:39.095 INFO  TaskSchedulerImpl - Removed TaskSet 751.0, whose tasks have all completed, from pool 
14:57:39.095 INFO  DAGScheduler - ShuffleMapStage 751 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
14:57:39.095 INFO  DAGScheduler - looking for newly runnable stages
14:57:39.095 INFO  DAGScheduler - running: HashSet()
14:57:39.095 INFO  DAGScheduler - waiting: HashSet(ResultStage 752)
14:57:39.095 INFO  DAGScheduler - failed: HashSet()
14:57:39.095 INFO  DAGScheduler - Submitting ResultStage 752 (MapPartitionsRDD[3548] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:57:39.096 INFO  MemoryStore - Block broadcast_1394 stored as values in memory (estimated size 20.2 KiB, free 1900.1 MiB)
14:57:39.096 INFO  MemoryStore - Block broadcast_1394_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1900.1 MiB)
14:57:39.097 INFO  BlockManagerInfo - Added broadcast_1394_piece0 in memory on localhost:35475 (size: 10.6 KiB, free: 1918.1 MiB)
14:57:39.097 INFO  SparkContext - Created broadcast 1394 from broadcast at DAGScheduler.scala:1580
14:57:39.097 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 752 (MapPartitionsRDD[3548] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:57:39.097 INFO  TaskSchedulerImpl - Adding task set 752.0 with 1 tasks resource profile 0
14:57:39.097 INFO  TaskSetManager - Starting task 0.0 in stage 752.0 (TID 689) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:57:39.098 INFO  Executor - Running task 0.0 in stage 752.0 (TID 689)
14:57:39.099 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:57:39.099 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.100 INFO  Executor - Finished task 0.0 in stage 752.0 (TID 689). 2010 bytes result sent to driver
14:57:39.101 INFO  TaskSetManager - Finished task 0.0 in stage 752.0 (TID 689) in 4 ms on localhost (executor driver) (1/1)
14:57:39.101 INFO  TaskSchedulerImpl - Removed TaskSet 752.0, whose tasks have all completed, from pool 
14:57:39.101 INFO  DAGScheduler - ResultStage 752 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
14:57:39.101 INFO  DAGScheduler - Job 427 is finished. Cancelling potential speculative or zombie tasks for this job
14:57:39.101 INFO  TaskSchedulerImpl - Killing all running tasks in stage 752: Stage finished
14:57:39.101 INFO  DAGScheduler - Job 427 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.030966 s
14:57:39.111 INFO  MemoryStore - Block broadcast_1395 stored as values in memory (estimated size 20.3 KiB, free 1900.0 MiB)
14:57:39.112 INFO  MemoryStore - Block broadcast_1395_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.0 MiB)
14:57:39.112 INFO  BlockManagerInfo - Added broadcast_1395_piece0 in memory on localhost:35475 (size: 1850.0 B, free: 1918.1 MiB)
14:57:39.112 INFO  SparkContext - Created broadcast 1395 from broadcast at ReadsSparkSink.java:133
14:57:39.113 INFO  MemoryStore - Block broadcast_1396 stored as values in memory (estimated size 20.4 KiB, free 1900.0 MiB)
14:57:39.113 INFO  MemoryStore - Block broadcast_1396_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.0 MiB)
14:57:39.113 INFO  BlockManagerInfo - Added broadcast_1396_piece0 in memory on localhost:35475 (size: 1850.0 B, free: 1918.1 MiB)
14:57:39.114 INFO  SparkContext - Created broadcast 1396 from broadcast at BamSink.java:76
14:57:39.115 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:57:39.115 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:57:39.115 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:57:39.132 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:57:39.133 INFO  DAGScheduler - Registering RDD 3550 (mapToPair at SparkUtils.java:161) as input to shuffle 109
14:57:39.133 INFO  DAGScheduler - Got job 428 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:57:39.133 INFO  DAGScheduler - Final stage: ResultStage 757 (runJob at SparkHadoopWriter.scala:83)
14:57:39.133 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 756)
14:57:39.133 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 756)
14:57:39.133 INFO  DAGScheduler - Submitting ShuffleMapStage 756 (MapPartitionsRDD[3550] at mapToPair at SparkUtils.java:161), which has no missing parents
14:57:39.134 INFO  MemoryStore - Block broadcast_1397 stored as values in memory (estimated size 18.1 KiB, free 1900.0 MiB)
14:57:39.134 INFO  MemoryStore - Block broadcast_1397_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1900.0 MiB)
14:57:39.135 INFO  BlockManagerInfo - Added broadcast_1397_piece0 in memory on localhost:35475 (size: 9.5 KiB, free: 1918.1 MiB)
14:57:39.135 INFO  SparkContext - Created broadcast 1397 from broadcast at DAGScheduler.scala:1580
14:57:39.135 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 756 (MapPartitionsRDD[3550] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:57:39.135 INFO  TaskSchedulerImpl - Adding task set 756.0 with 1 tasks resource profile 0
14:57:39.136 INFO  TaskSetManager - Starting task 0.0 in stage 756.0 (TID 690) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:57:39.136 INFO  Executor - Running task 0.0 in stage 756.0 (TID 690)
14:57:39.138 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:57:39.138 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.140 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:57:39.140 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.141 INFO  Executor - Finished task 0.0 in stage 756.0 (TID 690). 1922 bytes result sent to driver
14:57:39.141 INFO  TaskSetManager - Finished task 0.0 in stage 756.0 (TID 690) in 6 ms on localhost (executor driver) (1/1)
14:57:39.141 INFO  TaskSchedulerImpl - Removed TaskSet 756.0, whose tasks have all completed, from pool 
14:57:39.142 INFO  DAGScheduler - ShuffleMapStage 756 (mapToPair at SparkUtils.java:161) finished in 0.009 s
14:57:39.142 INFO  DAGScheduler - looking for newly runnable stages
14:57:39.142 INFO  DAGScheduler - running: HashSet()
14:57:39.142 INFO  DAGScheduler - waiting: HashSet(ResultStage 757)
14:57:39.142 INFO  DAGScheduler - failed: HashSet()
14:57:39.142 INFO  DAGScheduler - Submitting ResultStage 757 (MapPartitionsRDD[3555] at mapToPair at BamSink.java:91), which has no missing parents
14:57:39.148 INFO  MemoryStore - Block broadcast_1398 stored as values in memory (estimated size 163.7 KiB, free 1899.8 MiB)
14:57:39.149 INFO  MemoryStore - Block broadcast_1398_piece0 stored as bytes in memory (estimated size 73.9 KiB, free 1899.8 MiB)
14:57:39.149 INFO  BlockManagerInfo - Added broadcast_1398_piece0 in memory on localhost:35475 (size: 73.9 KiB, free: 1918.0 MiB)
14:57:39.150 INFO  SparkContext - Created broadcast 1398 from broadcast at DAGScheduler.scala:1580
14:57:39.150 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 757 (MapPartitionsRDD[3555] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
14:57:39.150 INFO  TaskSchedulerImpl - Adding task set 757.0 with 1 tasks resource profile 0
14:57:39.150 INFO  TaskSetManager - Starting task 0.0 in stage 757.0 (TID 691) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:57:39.150 INFO  Executor - Running task 0.0 in stage 757.0 (TID 691)
14:57:39.154 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:57:39.154 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:57:39.157 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:57:39.157 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:57:39.157 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:57:39.157 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:57:39.157 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:57:39.157 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:57:39.181 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271457398878767423425451663_3555_r_000000_0' to file:/tmp/local111378223953060423084/markdups2146228958652832183.bam.parts/_temporary/0/task_202505271457398878767423425451663_3555_r_000000
14:57:39.181 INFO  SparkHadoopMapRedUtil - attempt_202505271457398878767423425451663_3555_r_000000_0: Committed. Elapsed time: 0 ms.
14:57:39.182 INFO  Executor - Finished task 0.0 in stage 757.0 (TID 691). 1858 bytes result sent to driver
14:57:39.182 INFO  TaskSetManager - Finished task 0.0 in stage 757.0 (TID 691) in 32 ms on localhost (executor driver) (1/1)
14:57:39.182 INFO  TaskSchedulerImpl - Removed TaskSet 757.0, whose tasks have all completed, from pool 
14:57:39.183 INFO  DAGScheduler - ResultStage 757 (runJob at SparkHadoopWriter.scala:83) finished in 0.041 s
14:57:39.183 INFO  DAGScheduler - Job 428 is finished. Cancelling potential speculative or zombie tasks for this job
14:57:39.183 INFO  TaskSchedulerImpl - Killing all running tasks in stage 757: Stage finished
14:57:39.183 INFO  DAGScheduler - Job 428 finished: runJob at SparkHadoopWriter.scala:83, took 0.050620 s
14:57:39.183 INFO  SparkHadoopWriter - Start to commit write Job job_202505271457398878767423425451663_3555.
14:57:39.187 INFO  SparkHadoopWriter - Write Job job_202505271457398878767423425451663_3555 committed. Elapsed time: 4 ms.
14:57:39.198 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local111378223953060423084/markdups2146228958652832183.bam
14:57:39.201 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local111378223953060423084/markdups2146228958652832183.bam done
14:57:39.202 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local111378223953060423084/markdups2146228958652832183.bam.parts/ to /tmp/local111378223953060423084/markdups2146228958652832183.bam.sbi
14:57:39.206 INFO  IndexFileMerger - Done merging .sbi files
14:57:39.206 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local111378223953060423084/markdups2146228958652832183.bam.parts/ to /tmp/local111378223953060423084/markdups2146228958652832183.bam.bai
14:57:39.210 INFO  IndexFileMerger - Done merging .bai files
14:57:39.211 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:57:39 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:39 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:39 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:40 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:40 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:41 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:41 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:42 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:43 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:44 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:44 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:44 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:45 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:45 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:46 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:47 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:48 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:48 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:48 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:49 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:49 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:50 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:51 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:52 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:52 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:52 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:53 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:53 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:54 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:55 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:56 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:56 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:57 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:57 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:57 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:57:58 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:00 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:00 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:01 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:03 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:03 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
14:58:03.607 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:03.607 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
14:58:03.607 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:58:03.607 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:58:03.607 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:58:03.607 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:58:03 PM UTC
14:58:03.607 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:03.607 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:03.607 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:58:03.607 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:58:03.607 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:58:03.607 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:58:03.607 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:58:03.607 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:58:03.607 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:58:03.607 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:58:03.607 INFO  MarkDuplicatesSpark - Initializing engine
14:58:03.607 INFO  MarkDuplicatesSpark - Done initializing engine
14:58:03.607 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:58:03.610 INFO  MemoryStore - Block broadcast_1975 stored as values in memory (estimated size 306.3 KiB, free 1916.4 MiB)
14:58:03.617 INFO  MemoryStore - Block broadcast_1975_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1916.3 MiB)
14:58:03.617 INFO  BlockManagerInfo - Added broadcast_1975_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1919.1 MiB)
14:58:03.617 INFO  SparkContext - Created broadcast 1975 from newAPIHadoopFile at PathSplitSource.java:96
14:58:03.638 INFO  MemoryStore - Block broadcast_1976 stored as values in memory (estimated size 306.3 KiB, free 1916.0 MiB)
14:58:03.645 INFO  MemoryStore - Block broadcast_1976_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1915.9 MiB)
14:58:03.645 INFO  BlockManagerInfo - Added broadcast_1976_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1919.0 MiB)
14:58:03.645 INFO  SparkContext - Created broadcast 1976 from newAPIHadoopFile at PathSplitSource.java:96
14:58:03.678 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:58:03.679 INFO  FileInputFormat - Total input files to process : 1
14:58:03.679 INFO  DAGScheduler - Registering RDD 5447 (mapToPair at SparkUtils.java:161) as input to shuffle 300
14:58:03.679 INFO  DAGScheduler - Got job 559 (collect at SparkUtils.java:205) with 1 output partitions
14:58:03.679 INFO  DAGScheduler - Final stage: ResultStage 1219 (collect at SparkUtils.java:205)
14:58:03.679 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1218)
14:58:03.679 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1218)
14:58:03.680 INFO  DAGScheduler - Submitting ShuffleMapStage 1218 (MapPartitionsRDD[5447] at mapToPair at SparkUtils.java:161), which has no missing parents
14:58:03.697 INFO  MemoryStore - Block broadcast_1977 stored as values in memory (estimated size 493.8 KiB, free 1915.4 MiB)
14:58:03.699 INFO  MemoryStore - Block broadcast_1977_piece0 stored as bytes in memory (estimated size 210.1 KiB, free 1915.2 MiB)
14:58:03.700 INFO  BlockManagerInfo - Added broadcast_1977_piece0 in memory on localhost:35475 (size: 210.1 KiB, free: 1918.8 MiB)
14:58:03.700 INFO  SparkContext - Created broadcast 1977 from broadcast at DAGScheduler.scala:1580
14:58:03.700 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1218 (MapPartitionsRDD[5447] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:58:03.700 INFO  TaskSchedulerImpl - Adding task set 1218.0 with 1 tasks resource profile 0
14:58:03.700 INFO  TaskSetManager - Starting task 0.0 in stage 1218.0 (TID 1062) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9758 bytes) 
14:58:03.701 INFO  Executor - Running task 0.0 in stage 1218.0 (TID 1062)
14:58:03.731 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam:0+13412
14:58:03.736 INFO  Executor - Finished task 0.0 in stage 1218.0 (TID 1062). 1148 bytes result sent to driver
14:58:03.736 INFO  TaskSetManager - Finished task 0.0 in stage 1218.0 (TID 1062) in 36 ms on localhost (executor driver) (1/1)
14:58:03.736 INFO  TaskSchedulerImpl - Removed TaskSet 1218.0, whose tasks have all completed, from pool 
14:58:03.736 INFO  DAGScheduler - ShuffleMapStage 1218 (mapToPair at SparkUtils.java:161) finished in 0.056 s
14:58:03.736 INFO  DAGScheduler - looking for newly runnable stages
14:58:03.737 INFO  DAGScheduler - running: HashSet()
14:58:03.737 INFO  DAGScheduler - waiting: HashSet(ResultStage 1219)
14:58:03.737 INFO  DAGScheduler - failed: HashSet()
14:58:03.737 INFO  DAGScheduler - Submitting ResultStage 1219 (MapPartitionsRDD[5450] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:58:03.737 INFO  MemoryStore - Block broadcast_1978 stored as values in memory (estimated size 7.4 KiB, free 1915.2 MiB)
14:58:03.738 INFO  MemoryStore - Block broadcast_1978_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1915.2 MiB)
14:58:03.738 INFO  BlockManagerInfo - Added broadcast_1978_piece0 in memory on localhost:35475 (size: 4.1 KiB, free: 1918.8 MiB)
14:58:03.738 INFO  SparkContext - Created broadcast 1978 from broadcast at DAGScheduler.scala:1580
14:58:03.738 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1219 (MapPartitionsRDD[5450] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:58:03.738 INFO  TaskSchedulerImpl - Adding task set 1219.0 with 1 tasks resource profile 0
14:58:03.738 INFO  TaskSetManager - Starting task 0.0 in stage 1219.0 (TID 1063) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:03.739 INFO  Executor - Running task 0.0 in stage 1219.0 (TID 1063)
14:58:03.739 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:58:03.740 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.742 INFO  Executor - Finished task 0.0 in stage 1219.0 (TID 1063). 2329 bytes result sent to driver
14:58:03.742 INFO  TaskSetManager - Finished task 0.0 in stage 1219.0 (TID 1063) in 4 ms on localhost (executor driver) (1/1)
14:58:03.742 INFO  TaskSchedulerImpl - Removed TaskSet 1219.0, whose tasks have all completed, from pool 
14:58:03.742 INFO  DAGScheduler - ResultStage 1219 (collect at SparkUtils.java:205) finished in 0.005 s
14:58:03.743 INFO  DAGScheduler - Job 559 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:03.743 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1219: Stage finished
14:58:03.743 INFO  DAGScheduler - Job 559 finished: collect at SparkUtils.java:205, took 0.064402 s
14:58:03.747 INFO  MemoryStore - Block broadcast_1979 stored as values in memory (estimated size 7.8 KiB, free 1915.2 MiB)
14:58:03.747 INFO  MemoryStore - Block broadcast_1979_piece0 stored as bytes in memory (estimated size 540.0 B, free 1915.2 MiB)
14:58:03.747 INFO  BlockManagerInfo - Added broadcast_1979_piece0 in memory on localhost:35475 (size: 540.0 B, free: 1918.8 MiB)
14:58:03.748 INFO  SparkContext - Created broadcast 1979 from broadcast at MarkDuplicatesSparkUtils.java:126
14:58:03.748 INFO  MemoryStore - Block broadcast_1980 stored as values in memory (estimated size 2.6 KiB, free 1915.2 MiB)
14:58:03.748 INFO  MemoryStore - Block broadcast_1980_piece0 stored as bytes in memory (estimated size 209.0 B, free 1915.2 MiB)
14:58:03.748 INFO  BlockManagerInfo - Added broadcast_1980_piece0 in memory on localhost:35475 (size: 209.0 B, free: 1918.8 MiB)
14:58:03.748 INFO  SparkContext - Created broadcast 1980 from broadcast at MarkDuplicatesSparkUtils.java:127
14:58:03.762 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:58:03.762 INFO  DAGScheduler - Registering RDD 5459 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 303
14:58:03.763 INFO  DAGScheduler - Registering RDD 5463 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 302
14:58:03.763 INFO  DAGScheduler - Registering RDD 5467 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 301
14:58:03.763 INFO  DAGScheduler - Got job 560 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:58:03.763 INFO  DAGScheduler - Final stage: ResultStage 1224 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:58:03.763 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1223)
14:58:03.763 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1223)
14:58:03.763 INFO  DAGScheduler - Submitting ShuffleMapStage 1221 (MapPartitionsRDD[5459] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:58:03.764 INFO  MemoryStore - Block broadcast_1981 stored as values in memory (estimated size 57.6 KiB, free 1915.2 MiB)
14:58:03.765 INFO  MemoryStore - Block broadcast_1981_piece0 stored as bytes in memory (estimated size 19.8 KiB, free 1915.1 MiB)
14:58:03.765 INFO  BlockManagerInfo - Added broadcast_1981_piece0 in memory on localhost:35475 (size: 19.8 KiB, free: 1918.8 MiB)
14:58:03.765 INFO  SparkContext - Created broadcast 1981 from broadcast at DAGScheduler.scala:1580
14:58:03.765 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1221 (MapPartitionsRDD[5459] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:58:03.765 INFO  TaskSchedulerImpl - Adding task set 1221.0 with 1 tasks resource profile 0
14:58:03.766 INFO  TaskSetManager - Starting task 0.0 in stage 1221.0 (TID 1064) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
14:58:03.766 INFO  Executor - Running task 0.0 in stage 1221.0 (TID 1064)
14:58:03.767 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:58:03.767 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.771 INFO  Executor - Finished task 0.0 in stage 1221.0 (TID 1064). 1922 bytes result sent to driver
14:58:03.771 INFO  TaskSetManager - Finished task 0.0 in stage 1221.0 (TID 1064) in 6 ms on localhost (executor driver) (1/1)
14:58:03.772 INFO  TaskSchedulerImpl - Removed TaskSet 1221.0, whose tasks have all completed, from pool 
14:58:03.772 INFO  DAGScheduler - ShuffleMapStage 1221 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.009 s
14:58:03.772 INFO  DAGScheduler - looking for newly runnable stages
14:58:03.772 INFO  DAGScheduler - running: HashSet()
14:58:03.772 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1222, ShuffleMapStage 1223, ResultStage 1224)
14:58:03.772 INFO  DAGScheduler - failed: HashSet()
14:58:03.772 INFO  DAGScheduler - Submitting ShuffleMapStage 1222 (MapPartitionsRDD[5463] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:58:03.773 INFO  MemoryStore - Block broadcast_1982 stored as values in memory (estimated size 61.7 KiB, free 1915.1 MiB)
14:58:03.774 INFO  MemoryStore - Block broadcast_1982_piece0 stored as bytes in memory (estimated size 22.0 KiB, free 1915.1 MiB)
14:58:03.774 INFO  BlockManagerInfo - Added broadcast_1982_piece0 in memory on localhost:35475 (size: 22.0 KiB, free: 1918.8 MiB)
14:58:03.774 INFO  SparkContext - Created broadcast 1982 from broadcast at DAGScheduler.scala:1580
14:58:03.775 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1222 (MapPartitionsRDD[5463] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:58:03.775 INFO  TaskSchedulerImpl - Adding task set 1222.0 with 1 tasks resource profile 0
14:58:03.775 INFO  TaskSetManager - Starting task 0.0 in stage 1222.0 (TID 1065) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
14:58:03.775 INFO  Executor - Running task 0.0 in stage 1222.0 (TID 1065)
14:58:03.778 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:58:03.778 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.785 INFO  Executor - Finished task 0.0 in stage 1222.0 (TID 1065). 1922 bytes result sent to driver
14:58:03.786 INFO  TaskSetManager - Finished task 0.0 in stage 1222.0 (TID 1065) in 11 ms on localhost (executor driver) (1/1)
14:58:03.786 INFO  TaskSchedulerImpl - Removed TaskSet 1222.0, whose tasks have all completed, from pool 
14:58:03.786 INFO  DAGScheduler - ShuffleMapStage 1222 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.014 s
14:58:03.786 INFO  DAGScheduler - looking for newly runnable stages
14:58:03.786 INFO  DAGScheduler - running: HashSet()
14:58:03.786 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1223, ResultStage 1224)
14:58:03.786 INFO  DAGScheduler - failed: HashSet()
14:58:03.786 INFO  DAGScheduler - Submitting ShuffleMapStage 1223 (MapPartitionsRDD[5467] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:58:03.787 INFO  MemoryStore - Block broadcast_1983 stored as values in memory (estimated size 52.4 KiB, free 1915.0 MiB)
14:58:03.788 INFO  MemoryStore - Block broadcast_1983_piece0 stored as bytes in memory (estimated size 17.3 KiB, free 1915.0 MiB)
14:58:03.788 INFO  BlockManagerInfo - Added broadcast_1983_piece0 in memory on localhost:35475 (size: 17.3 KiB, free: 1918.8 MiB)
14:58:03.788 INFO  SparkContext - Created broadcast 1983 from broadcast at DAGScheduler.scala:1580
14:58:03.788 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1223 (MapPartitionsRDD[5467] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:58:03.788 INFO  TaskSchedulerImpl - Adding task set 1223.0 with 1 tasks resource profile 0
14:58:03.788 INFO  TaskSetManager - Starting task 0.0 in stage 1223.0 (TID 1066) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:58:03.789 INFO  Executor - Running task 0.0 in stage 1223.0 (TID 1066)
14:58:03.790 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:58:03.790 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.793 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:58:03.793 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.795 INFO  Executor - Finished task 0.0 in stage 1223.0 (TID 1066). 1922 bytes result sent to driver
14:58:03.795 INFO  TaskSetManager - Finished task 0.0 in stage 1223.0 (TID 1066) in 7 ms on localhost (executor driver) (1/1)
14:58:03.795 INFO  TaskSchedulerImpl - Removed TaskSet 1223.0, whose tasks have all completed, from pool 
14:58:03.795 INFO  DAGScheduler - ShuffleMapStage 1223 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.009 s
14:58:03.795 INFO  DAGScheduler - looking for newly runnable stages
14:58:03.795 INFO  DAGScheduler - running: HashSet()
14:58:03.795 INFO  DAGScheduler - waiting: HashSet(ResultStage 1224)
14:58:03.795 INFO  DAGScheduler - failed: HashSet()
14:58:03.795 INFO  DAGScheduler - Submitting ResultStage 1224 (MapPartitionsRDD[5469] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:58:03.796 INFO  MemoryStore - Block broadcast_1984 stored as values in memory (estimated size 53.6 KiB, free 1914.9 MiB)
14:58:03.797 INFO  MemoryStore - Block broadcast_1984_piece0 stored as bytes in memory (estimated size 18.0 KiB, free 1914.9 MiB)
14:58:03.797 INFO  BlockManagerInfo - Added broadcast_1984_piece0 in memory on localhost:35475 (size: 18.0 KiB, free: 1918.7 MiB)
14:58:03.797 INFO  SparkContext - Created broadcast 1984 from broadcast at DAGScheduler.scala:1580
14:58:03.797 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1224 (MapPartitionsRDD[5469] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:58:03.797 INFO  TaskSchedulerImpl - Adding task set 1224.0 with 1 tasks resource profile 0
14:58:03.797 INFO  TaskSetManager - Starting task 0.0 in stage 1224.0 (TID 1067) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:03.797 INFO  Executor - Running task 0.0 in stage 1224.0 (TID 1067)
14:58:03.799 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:58:03.799 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.800 INFO  Executor - Finished task 0.0 in stage 1224.0 (TID 1067). 2371 bytes result sent to driver
14:58:03.800 INFO  TaskSetManager - Finished task 0.0 in stage 1224.0 (TID 1067) in 3 ms on localhost (executor driver) (1/1)
14:58:03.800 INFO  TaskSchedulerImpl - Removed TaskSet 1224.0, whose tasks have all completed, from pool 
14:58:03.800 INFO  DAGScheduler - ResultStage 1224 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
14:58:03.801 INFO  DAGScheduler - Job 560 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:03.801 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1224: Stage finished
14:58:03.801 INFO  DAGScheduler - Job 560 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.038569 s
14:58:03.812 INFO  MemoryStore - Block broadcast_1985 stored as values in memory (estimated size 179.4 KiB, free 1914.8 MiB)
14:58:03.813 INFO  MemoryStore - Block broadcast_1985_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1914.7 MiB)
14:58:03.813 INFO  BlockManagerInfo - Added broadcast_1985_piece0 in memory on localhost:35475 (size: 7.9 KiB, free: 1918.7 MiB)
14:58:03.813 INFO  SparkContext - Created broadcast 1985 from broadcast at ReadsSparkSink.java:133
14:58:03.817 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:58:03.817 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:58:03.817 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:58:03.833 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:58:03.833 INFO  DAGScheduler - Registering RDD 5471 (mapToPair at SparkUtils.java:161) as input to shuffle 304
14:58:03.833 INFO  DAGScheduler - Got job 561 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:58:03.833 INFO  DAGScheduler - Final stage: ResultStage 1229 (runJob at SparkHadoopWriter.scala:83)
14:58:03.833 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1228)
14:58:03.833 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1228)
14:58:03.833 INFO  DAGScheduler - Submitting ShuffleMapStage 1228 (MapPartitionsRDD[5471] at mapToPair at SparkUtils.java:161), which has no missing parents
14:58:03.834 INFO  MemoryStore - Block broadcast_1986 stored as values in memory (estimated size 51.5 KiB, free 1914.7 MiB)
14:58:03.835 INFO  MemoryStore - Block broadcast_1986_piece0 stored as bytes in memory (estimated size 16.8 KiB, free 1914.7 MiB)
14:58:03.835 INFO  BlockManagerInfo - Added broadcast_1986_piece0 in memory on localhost:35475 (size: 16.8 KiB, free: 1918.7 MiB)
14:58:03.835 INFO  SparkContext - Created broadcast 1986 from broadcast at DAGScheduler.scala:1580
14:58:03.835 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1228 (MapPartitionsRDD[5471] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:58:03.835 INFO  TaskSchedulerImpl - Adding task set 1228.0 with 1 tasks resource profile 0
14:58:03.836 INFO  TaskSetManager - Starting task 0.0 in stage 1228.0 (TID 1068) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:58:03.836 INFO  Executor - Running task 0.0 in stage 1228.0 (TID 1068)
14:58:03.837 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:58:03.837 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.840 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:58:03.840 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.841 INFO  Executor - Finished task 0.0 in stage 1228.0 (TID 1068). 1922 bytes result sent to driver
14:58:03.842 INFO  TaskSetManager - Finished task 0.0 in stage 1228.0 (TID 1068) in 7 ms on localhost (executor driver) (1/1)
14:58:03.842 INFO  TaskSchedulerImpl - Removed TaskSet 1228.0, whose tasks have all completed, from pool 
14:58:03.842 INFO  DAGScheduler - ShuffleMapStage 1228 (mapToPair at SparkUtils.java:161) finished in 0.008 s
14:58:03.842 INFO  DAGScheduler - looking for newly runnable stages
14:58:03.842 INFO  DAGScheduler - running: HashSet()
14:58:03.842 INFO  DAGScheduler - waiting: HashSet(ResultStage 1229)
14:58:03.842 INFO  DAGScheduler - failed: HashSet()
14:58:03.842 INFO  DAGScheduler - Submitting ResultStage 1229 (MapPartitionsRDD[5477] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:58:03.849 INFO  MemoryStore - Block broadcast_1987 stored as values in memory (estimated size 196.7 KiB, free 1914.5 MiB)
14:58:03.850 INFO  MemoryStore - Block broadcast_1987_piece0 stored as bytes in memory (estimated size 80.9 KiB, free 1914.4 MiB)
14:58:03.850 INFO  BlockManagerInfo - Added broadcast_1987_piece0 in memory on localhost:35475 (size: 80.9 KiB, free: 1918.6 MiB)
14:58:03.850 INFO  SparkContext - Created broadcast 1987 from broadcast at DAGScheduler.scala:1580
14:58:03.850 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1229 (MapPartitionsRDD[5477] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
14:58:03.850 INFO  TaskSchedulerImpl - Adding task set 1229.0 with 1 tasks resource profile 0
14:58:03.850 INFO  TaskSetManager - Starting task 0.0 in stage 1229.0 (TID 1069) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:03.850 INFO  Executor - Running task 0.0 in stage 1229.0 (TID 1069)
14:58:03.854 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:58:03.854 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:03.856 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:58:03.856 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:58:03.856 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:58:03.867 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271458038935389061136926524_5477_m_000000_0' to file:/tmp/MarkDups12412320108851936511/MarkDups.sam.parts/_temporary/0/task_202505271458038935389061136926524_5477_m_000000
14:58:03.867 INFO  SparkHadoopMapRedUtil - attempt_202505271458038935389061136926524_5477_m_000000_0: Committed. Elapsed time: 0 ms.
14:58:03.867 INFO  Executor - Finished task 0.0 in stage 1229.0 (TID 1069). 1858 bytes result sent to driver
14:58:03.867 INFO  TaskSetManager - Finished task 0.0 in stage 1229.0 (TID 1069) in 17 ms on localhost (executor driver) (1/1)
14:58:03.867 INFO  TaskSchedulerImpl - Removed TaskSet 1229.0, whose tasks have all completed, from pool 
14:58:03.867 INFO  DAGScheduler - ResultStage 1229 (runJob at SparkHadoopWriter.scala:83) finished in 0.025 s
14:58:03.867 INFO  DAGScheduler - Job 561 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:03.868 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1229: Stage finished
14:58:03.868 INFO  DAGScheduler - Job 561 finished: runJob at SparkHadoopWriter.scala:83, took 0.034868 s
14:58:03.868 INFO  SparkHadoopWriter - Start to commit write Job job_202505271458038935389061136926524_5477.
14:58:03.872 INFO  SparkHadoopWriter - Write Job job_202505271458038935389061136926524_5477 committed. Elapsed time: 3 ms.
14:58:03.879 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups12412320108851936511/MarkDups.sam
14:58:03.882 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups12412320108851936511/MarkDups.sam done
14:58:03.882 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:58:03 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
14:58:03.888 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:03.888 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
14:58:03.888 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:58:03.888 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:58:03.888 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:58:03.888 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:58:03 PM UTC
14:58:03.888 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:03.888 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:03.888 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:58:03.888 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:58:03.888 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:58:03.888 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:58:03.888 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:58:03.888 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:58:03.888 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:58:03.888 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:58:03.888 INFO  MarkDuplicatesSpark - Initializing engine
14:58:03.888 INFO  MarkDuplicatesSpark - Done initializing engine
14:58:03.888 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:58:03.890 INFO  MemoryStore - Block broadcast_1988 stored as values in memory (estimated size 306.3 KiB, free 1914.1 MiB)
14:58:03.897 INFO  MemoryStore - Block broadcast_1988_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1914.0 MiB)
14:58:03.897 INFO  BlockManagerInfo - Added broadcast_1988_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.6 MiB)
14:58:03.897 INFO  SparkContext - Created broadcast 1988 from newAPIHadoopFile at PathSplitSource.java:96
14:58:03.917 INFO  MemoryStore - Block broadcast_1989 stored as values in memory (estimated size 306.3 KiB, free 1913.7 MiB)
14:58:03.924 INFO  MemoryStore - Block broadcast_1989_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1913.7 MiB)
14:58:03.924 INFO  BlockManagerInfo - Added broadcast_1989_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.5 MiB)
14:58:03.924 INFO  SparkContext - Created broadcast 1989 from newAPIHadoopFile at PathSplitSource.java:96
14:58:03.956 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:58:03.957 INFO  FileInputFormat - Total input files to process : 1
14:58:03.957 INFO  DAGScheduler - Registering RDD 5491 (mapToPair at SparkUtils.java:161) as input to shuffle 305
14:58:03.957 INFO  DAGScheduler - Got job 562 (collect at SparkUtils.java:205) with 1 output partitions
14:58:03.957 INFO  DAGScheduler - Final stage: ResultStage 1231 (collect at SparkUtils.java:205)
14:58:03.957 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1230)
14:58:03.957 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1230)
14:58:03.957 INFO  DAGScheduler - Submitting ShuffleMapStage 1230 (MapPartitionsRDD[5491] at mapToPair at SparkUtils.java:161), which has no missing parents
14:58:03.974 INFO  MemoryStore - Block broadcast_1990 stored as values in memory (estimated size 457.4 KiB, free 1913.2 MiB)
14:58:03.976 INFO  MemoryStore - Block broadcast_1990_piece0 stored as bytes in memory (estimated size 201.1 KiB, free 1913.0 MiB)
14:58:03.977 INFO  BlockManagerInfo - Added broadcast_1990_piece0 in memory on localhost:35475 (size: 201.1 KiB, free: 1918.3 MiB)
14:58:03.977 INFO  SparkContext - Created broadcast 1990 from broadcast at DAGScheduler.scala:1580
14:58:03.977 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1230 (MapPartitionsRDD[5491] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:58:03.977 INFO  TaskSchedulerImpl - Adding task set 1230.0 with 1 tasks resource profile 0
14:58:03.977 INFO  TaskSetManager - Starting task 0.0 in stage 1230.0 (TID 1070) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9738 bytes) 
14:58:03.978 INFO  Executor - Running task 0.0 in stage 1230.0 (TID 1070)
14:58:04.006 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam:0+678
14:58:04.010 INFO  Executor - Finished task 0.0 in stage 1230.0 (TID 1070). 1148 bytes result sent to driver
14:58:04.010 INFO  TaskSetManager - Finished task 0.0 in stage 1230.0 (TID 1070) in 33 ms on localhost (executor driver) (1/1)
14:58:04.010 INFO  TaskSchedulerImpl - Removed TaskSet 1230.0, whose tasks have all completed, from pool 
14:58:04.010 INFO  DAGScheduler - ShuffleMapStage 1230 (mapToPair at SparkUtils.java:161) finished in 0.052 s
14:58:04.010 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.010 INFO  DAGScheduler - running: HashSet()
14:58:04.011 INFO  DAGScheduler - waiting: HashSet(ResultStage 1231)
14:58:04.011 INFO  DAGScheduler - failed: HashSet()
14:58:04.011 INFO  DAGScheduler - Submitting ResultStage 1231 (MapPartitionsRDD[5494] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:58:04.011 INFO  MemoryStore - Block broadcast_1991 stored as values in memory (estimated size 7.4 KiB, free 1913.0 MiB)
14:58:04.011 INFO  MemoryStore - Block broadcast_1991_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1913.0 MiB)
14:58:04.011 INFO  BlockManagerInfo - Added broadcast_1991_piece0 in memory on localhost:35475 (size: 4.1 KiB, free: 1918.3 MiB)
14:58:04.012 INFO  SparkContext - Created broadcast 1991 from broadcast at DAGScheduler.scala:1580
14:58:04.012 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1231 (MapPartitionsRDD[5494] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:58:04.012 INFO  TaskSchedulerImpl - Adding task set 1231.0 with 1 tasks resource profile 0
14:58:04.012 INFO  TaskSetManager - Starting task 0.0 in stage 1231.0 (TID 1071) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:04.012 INFO  Executor - Running task 0.0 in stage 1231.0 (TID 1071)
14:58:04.013 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:58:04.013 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.014 INFO  Executor - Finished task 0.0 in stage 1231.0 (TID 1071). 2269 bytes result sent to driver
14:58:04.014 INFO  TaskSetManager - Finished task 0.0 in stage 1231.0 (TID 1071) in 2 ms on localhost (executor driver) (1/1)
14:58:04.014 INFO  TaskSchedulerImpl - Removed TaskSet 1231.0, whose tasks have all completed, from pool 
14:58:04.015 INFO  DAGScheduler - ResultStage 1231 (collect at SparkUtils.java:205) finished in 0.004 s
14:58:04.015 INFO  DAGScheduler - Job 562 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:04.015 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1231: Stage finished
14:58:04.015 INFO  DAGScheduler - Job 562 finished: collect at SparkUtils.java:205, took 0.058287 s
14:58:04.019 INFO  MemoryStore - Block broadcast_1992 stored as values in memory (estimated size 136.0 B, free 1913.0 MiB)
14:58:04.019 INFO  MemoryStore - Block broadcast_1992_piece0 stored as bytes in memory (estimated size 24.0 B, free 1913.0 MiB)
14:58:04.019 INFO  BlockManagerInfo - Added broadcast_1992_piece0 in memory on localhost:35475 (size: 24.0 B, free: 1918.3 MiB)
14:58:04.019 INFO  SparkContext - Created broadcast 1992 from broadcast at MarkDuplicatesSparkUtils.java:126
14:58:04.019 INFO  MemoryStore - Block broadcast_1993 stored as values in memory (estimated size 136.0 B, free 1913.0 MiB)
14:58:04.020 INFO  MemoryStore - Block broadcast_1993_piece0 stored as bytes in memory (estimated size 21.0 B, free 1913.0 MiB)
14:58:04.020 INFO  BlockManagerInfo - Added broadcast_1993_piece0 in memory on localhost:35475 (size: 21.0 B, free: 1918.3 MiB)
14:58:04.020 INFO  SparkContext - Created broadcast 1993 from broadcast at MarkDuplicatesSparkUtils.java:127
14:58:04.031 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:58:04.032 INFO  DAGScheduler - Registering RDD 5503 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 308
14:58:04.032 INFO  DAGScheduler - Registering RDD 5507 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 307
14:58:04.032 INFO  DAGScheduler - Registering RDD 5511 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 306
14:58:04.032 INFO  DAGScheduler - Got job 563 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:58:04.032 INFO  DAGScheduler - Final stage: ResultStage 1236 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:58:04.032 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1235)
14:58:04.032 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1235)
14:58:04.032 INFO  DAGScheduler - Submitting ShuffleMapStage 1233 (MapPartitionsRDD[5503] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:58:04.033 INFO  MemoryStore - Block broadcast_1994 stored as values in memory (estimated size 21.1 KiB, free 1913.0 MiB)
14:58:04.033 INFO  MemoryStore - Block broadcast_1994_piece0 stored as bytes in memory (estimated size 10.9 KiB, free 1913.0 MiB)
14:58:04.033 INFO  BlockManagerInfo - Added broadcast_1994_piece0 in memory on localhost:35475 (size: 10.9 KiB, free: 1918.3 MiB)
14:58:04.034 INFO  SparkContext - Created broadcast 1994 from broadcast at DAGScheduler.scala:1580
14:58:04.034 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1233 (MapPartitionsRDD[5503] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:58:04.034 INFO  TaskSchedulerImpl - Adding task set 1233.0 with 1 tasks resource profile 0
14:58:04.034 INFO  TaskSetManager - Starting task 0.0 in stage 1233.0 (TID 1072) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
14:58:04.034 INFO  Executor - Running task 0.0 in stage 1233.0 (TID 1072)
14:58:04.036 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:58:04.036 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.038 INFO  Executor - Finished task 0.0 in stage 1233.0 (TID 1072). 1879 bytes result sent to driver
14:58:04.038 INFO  TaskSetManager - Finished task 0.0 in stage 1233.0 (TID 1072) in 4 ms on localhost (executor driver) (1/1)
14:58:04.038 INFO  TaskSchedulerImpl - Removed TaskSet 1233.0, whose tasks have all completed, from pool 
14:58:04.038 INFO  DAGScheduler - ShuffleMapStage 1233 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.005 s
14:58:04.038 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.038 INFO  DAGScheduler - running: HashSet()
14:58:04.038 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1234, ShuffleMapStage 1235, ResultStage 1236)
14:58:04.038 INFO  DAGScheduler - failed: HashSet()
14:58:04.038 INFO  DAGScheduler - Submitting ShuffleMapStage 1234 (MapPartitionsRDD[5507] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:58:04.039 INFO  MemoryStore - Block broadcast_1995 stored as values in memory (estimated size 25.2 KiB, free 1913.0 MiB)
14:58:04.039 INFO  MemoryStore - Block broadcast_1995_piece0 stored as bytes in memory (estimated size 13.1 KiB, free 1913.0 MiB)
14:58:04.039 INFO  BlockManagerInfo - Added broadcast_1995_piece0 in memory on localhost:35475 (size: 13.1 KiB, free: 1918.3 MiB)
14:58:04.039 INFO  SparkContext - Created broadcast 1995 from broadcast at DAGScheduler.scala:1580
14:58:04.039 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1234 (MapPartitionsRDD[5507] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:58:04.039 INFO  TaskSchedulerImpl - Adding task set 1234.0 with 1 tasks resource profile 0
14:58:04.040 INFO  TaskSetManager - Starting task 0.0 in stage 1234.0 (TID 1073) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
14:58:04.040 INFO  Executor - Running task 0.0 in stage 1234.0 (TID 1073)
14:58:04.041 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:58:04.041 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.045 INFO  Executor - Finished task 0.0 in stage 1234.0 (TID 1073). 1879 bytes result sent to driver
14:58:04.045 INFO  TaskSetManager - Finished task 0.0 in stage 1234.0 (TID 1073) in 5 ms on localhost (executor driver) (1/1)
14:58:04.045 INFO  TaskSchedulerImpl - Removed TaskSet 1234.0, whose tasks have all completed, from pool 
14:58:04.045 INFO  DAGScheduler - ShuffleMapStage 1234 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
14:58:04.045 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.045 INFO  DAGScheduler - running: HashSet()
14:58:04.045 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1235, ResultStage 1236)
14:58:04.045 INFO  DAGScheduler - failed: HashSet()
14:58:04.045 INFO  DAGScheduler - Submitting ShuffleMapStage 1235 (MapPartitionsRDD[5511] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:58:04.046 INFO  MemoryStore - Block broadcast_1996 stored as values in memory (estimated size 15.9 KiB, free 1912.9 MiB)
14:58:04.046 INFO  MemoryStore - Block broadcast_1996_piece0 stored as bytes in memory (estimated size 8.3 KiB, free 1912.9 MiB)
14:58:04.046 INFO  BlockManagerInfo - Added broadcast_1996_piece0 in memory on localhost:35475 (size: 8.3 KiB, free: 1918.3 MiB)
14:58:04.046 INFO  SparkContext - Created broadcast 1996 from broadcast at DAGScheduler.scala:1580
14:58:04.047 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1235 (MapPartitionsRDD[5511] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:58:04.047 INFO  TaskSchedulerImpl - Adding task set 1235.0 with 1 tasks resource profile 0
14:58:04.047 INFO  TaskSetManager - Starting task 0.0 in stage 1235.0 (TID 1074) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:58:04.047 INFO  Executor - Running task 0.0 in stage 1235.0 (TID 1074)
14:58:04.048 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:58:04.048 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.049 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:58:04.049 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.050 INFO  Executor - Finished task 0.0 in stage 1235.0 (TID 1074). 1879 bytes result sent to driver
14:58:04.050 INFO  TaskSetManager - Finished task 0.0 in stage 1235.0 (TID 1074) in 3 ms on localhost (executor driver) (1/1)
14:58:04.050 INFO  TaskSchedulerImpl - Removed TaskSet 1235.0, whose tasks have all completed, from pool 
14:58:04.051 INFO  DAGScheduler - ShuffleMapStage 1235 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
14:58:04.051 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.051 INFO  DAGScheduler - running: HashSet()
14:58:04.051 INFO  DAGScheduler - waiting: HashSet(ResultStage 1236)
14:58:04.051 INFO  DAGScheduler - failed: HashSet()
14:58:04.051 INFO  DAGScheduler - Submitting ResultStage 1236 (MapPartitionsRDD[5513] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:58:04.051 INFO  MemoryStore - Block broadcast_1997 stored as values in memory (estimated size 17.1 KiB, free 1912.9 MiB)
14:58:04.052 INFO  MemoryStore - Block broadcast_1997_piece0 stored as bytes in memory (estimated size 9.0 KiB, free 1912.9 MiB)
14:58:04.052 INFO  BlockManagerInfo - Added broadcast_1997_piece0 in memory on localhost:35475 (size: 9.0 KiB, free: 1918.3 MiB)
14:58:04.052 INFO  SparkContext - Created broadcast 1997 from broadcast at DAGScheduler.scala:1580
14:58:04.052 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1236 (MapPartitionsRDD[5513] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:58:04.052 INFO  TaskSchedulerImpl - Adding task set 1236.0 with 1 tasks resource profile 0
14:58:04.052 INFO  TaskSetManager - Starting task 0.0 in stage 1236.0 (TID 1075) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:04.052 INFO  Executor - Running task 0.0 in stage 1236.0 (TID 1075)
14:58:04.054 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:58:04.054 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.055 INFO  Executor - Finished task 0.0 in stage 1236.0 (TID 1075). 1887 bytes result sent to driver
14:58:04.055 INFO  TaskSetManager - Finished task 0.0 in stage 1236.0 (TID 1075) in 3 ms on localhost (executor driver) (1/1)
14:58:04.055 INFO  TaskSchedulerImpl - Removed TaskSet 1236.0, whose tasks have all completed, from pool 
14:58:04.055 INFO  DAGScheduler - ResultStage 1236 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.004 s
14:58:04.055 INFO  DAGScheduler - Job 563 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:04.055 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1236: Stage finished
14:58:04.055 INFO  DAGScheduler - Job 563 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.023801 s
14:58:04.065 INFO  MemoryStore - Block broadcast_1998 stored as values in memory (estimated size 5.6 KiB, free 1912.9 MiB)
14:58:04.066 INFO  MemoryStore - Block broadcast_1998_piece0 stored as bytes in memory (estimated size 500.0 B, free 1912.9 MiB)
14:58:04.066 INFO  BlockManagerInfo - Added broadcast_1998_piece0 in memory on localhost:35475 (size: 500.0 B, free: 1918.3 MiB)
14:58:04.066 INFO  SparkContext - Created broadcast 1998 from broadcast at ReadsSparkSink.java:133
14:58:04.069 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:58:04.069 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:58:04.069 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:58:04.085 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:58:04.086 INFO  DAGScheduler - Registering RDD 5515 (mapToPair at SparkUtils.java:161) as input to shuffle 309
14:58:04.086 INFO  DAGScheduler - Got job 564 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:58:04.086 INFO  DAGScheduler - Final stage: ResultStage 1241 (runJob at SparkHadoopWriter.scala:83)
14:58:04.086 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1240)
14:58:04.086 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1240)
14:58:04.086 INFO  DAGScheduler - Submitting ShuffleMapStage 1240 (MapPartitionsRDD[5515] at mapToPair at SparkUtils.java:161), which has no missing parents
14:58:04.087 INFO  MemoryStore - Block broadcast_1999 stored as values in memory (estimated size 15.0 KiB, free 1912.9 MiB)
14:58:04.087 INFO  MemoryStore - Block broadcast_1999_piece0 stored as bytes in memory (estimated size 7.8 KiB, free 1912.9 MiB)
14:58:04.087 INFO  BlockManagerInfo - Added broadcast_1999_piece0 in memory on localhost:35475 (size: 7.8 KiB, free: 1918.3 MiB)
14:58:04.087 INFO  SparkContext - Created broadcast 1999 from broadcast at DAGScheduler.scala:1580
14:58:04.087 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1240 (MapPartitionsRDD[5515] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:58:04.087 INFO  TaskSchedulerImpl - Adding task set 1240.0 with 1 tasks resource profile 0
14:58:04.088 INFO  TaskSetManager - Starting task 0.0 in stage 1240.0 (TID 1076) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:58:04.088 INFO  Executor - Running task 0.0 in stage 1240.0 (TID 1076)
14:58:04.089 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:58:04.089 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.091 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:58:04.091 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.092 INFO  Executor - Finished task 0.0 in stage 1240.0 (TID 1076). 1922 bytes result sent to driver
14:58:04.092 INFO  TaskSetManager - Finished task 0.0 in stage 1240.0 (TID 1076) in 4 ms on localhost (executor driver) (1/1)
14:58:04.092 INFO  TaskSchedulerImpl - Removed TaskSet 1240.0, whose tasks have all completed, from pool 
14:58:04.092 INFO  DAGScheduler - ShuffleMapStage 1240 (mapToPair at SparkUtils.java:161) finished in 0.006 s
14:58:04.092 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.092 INFO  DAGScheduler - running: HashSet()
14:58:04.092 INFO  DAGScheduler - waiting: HashSet(ResultStage 1241)
14:58:04.092 INFO  DAGScheduler - failed: HashSet()
14:58:04.092 INFO  DAGScheduler - Submitting ResultStage 1241 (MapPartitionsRDD[5521] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:58:04.098 INFO  MemoryStore - Block broadcast_2000 stored as values in memory (estimated size 160.3 KiB, free 1912.7 MiB)
14:58:04.099 INFO  MemoryStore - Block broadcast_2000_piece0 stored as bytes in memory (estimated size 72.1 KiB, free 1912.7 MiB)
14:58:04.099 INFO  BlockManagerInfo - Added broadcast_2000_piece0 in memory on localhost:35475 (size: 72.1 KiB, free: 1918.2 MiB)
14:58:04.099 INFO  SparkContext - Created broadcast 2000 from broadcast at DAGScheduler.scala:1580
14:58:04.100 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1241 (MapPartitionsRDD[5521] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
14:58:04.100 INFO  TaskSchedulerImpl - Adding task set 1241.0 with 1 tasks resource profile 0
14:58:04.100 INFO  TaskSetManager - Starting task 0.0 in stage 1241.0 (TID 1077) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:04.100 INFO  Executor - Running task 0.0 in stage 1241.0 (TID 1077)
14:58:04.103 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:58:04.103 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.104 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:58:04.104 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:58:04.104 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:58:04.115 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271458048637630734274644140_5521_m_000000_0' to file:/tmp/MarkDups3485707580111076380/MarkDups.sam.parts/_temporary/0/task_202505271458048637630734274644140_5521_m_000000
14:58:04.116 INFO  SparkHadoopMapRedUtil - attempt_202505271458048637630734274644140_5521_m_000000_0: Committed. Elapsed time: 0 ms.
14:58:04.116 INFO  Executor - Finished task 0.0 in stage 1241.0 (TID 1077). 1858 bytes result sent to driver
14:58:04.116 INFO  TaskSetManager - Finished task 0.0 in stage 1241.0 (TID 1077) in 16 ms on localhost (executor driver) (1/1)
14:58:04.116 INFO  TaskSchedulerImpl - Removed TaskSet 1241.0, whose tasks have all completed, from pool 
14:58:04.116 INFO  DAGScheduler - ResultStage 1241 (runJob at SparkHadoopWriter.scala:83) finished in 0.024 s
14:58:04.116 INFO  DAGScheduler - Job 564 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:04.116 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1241: Stage finished
14:58:04.116 INFO  DAGScheduler - Job 564 finished: runJob at SparkHadoopWriter.scala:83, took 0.030854 s
14:58:04.116 INFO  SparkHadoopWriter - Start to commit write Job job_202505271458048637630734274644140_5521.
14:58:04.120 INFO  SparkHadoopWriter - Write Job job_202505271458048637630734274644140_5521 committed. Elapsed time: 3 ms.
14:58:04.128 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups3485707580111076380/MarkDups.sam
14:58:04.132 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups3485707580111076380/MarkDups.sam done
14:58:04.132 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:58:04 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
14:58:04.139 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:04.139 INFO  MarkDuplicatesSpark - org.broadinstitute.hellbender.tools.spark.transforms.markduplicates vUnavailable
14:58:04.139 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:58:04.139 INFO  MarkDuplicatesSpark - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:58:04.139 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:58:04.139 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:58:04 PM UTC
14:58:04.139 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:04.139 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:58:04.139 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:58:04.139 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:58:04.139 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:58:04.139 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:58:04.139 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:58:04.139 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:58:04.139 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:58:04.139 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:58:04.139 INFO  MarkDuplicatesSpark - Initializing engine
14:58:04.139 INFO  MarkDuplicatesSpark - Done initializing engine
14:58:04.139 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:58:04.142 INFO  MemoryStore - Block broadcast_2001 stored as values in memory (estimated size 306.3 KiB, free 1912.4 MiB)
14:58:04.153 INFO  MemoryStore - Block broadcast_2001_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1912.3 MiB)
14:58:04.153 INFO  BlockManagerInfo - Added broadcast_2001_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.1 MiB)
14:58:04.153 INFO  SparkContext - Created broadcast 2001 from newAPIHadoopFile at PathSplitSource.java:96
14:58:04.173 INFO  MemoryStore - Block broadcast_2002 stored as values in memory (estimated size 306.3 KiB, free 1912.0 MiB)
14:58:04.179 INFO  MemoryStore - Block broadcast_2002_piece0 stored as bytes in memory (estimated size 64.4 KiB, free 1911.9 MiB)
14:58:04.180 INFO  BlockManagerInfo - Added broadcast_2002_piece0 in memory on localhost:35475 (size: 64.4 KiB, free: 1918.1 MiB)
14:58:04.180 INFO  SparkContext - Created broadcast 2002 from newAPIHadoopFile at PathSplitSource.java:96
14:58:04.212 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:58:04.212 INFO  FileInputFormat - Total input files to process : 1
14:58:04.213 INFO  DAGScheduler - Registering RDD 5535 (mapToPair at SparkUtils.java:161) as input to shuffle 310
14:58:04.213 INFO  DAGScheduler - Got job 565 (collect at SparkUtils.java:205) with 1 output partitions
14:58:04.213 INFO  DAGScheduler - Final stage: ResultStage 1243 (collect at SparkUtils.java:205)
14:58:04.213 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1242)
14:58:04.213 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1242)
14:58:04.213 INFO  DAGScheduler - Submitting ShuffleMapStage 1242 (MapPartitionsRDD[5535] at mapToPair at SparkUtils.java:161), which has no missing parents
14:58:04.218 INFO  BlockManagerInfo - Removed broadcast_1992_piece0 on localhost:35475 in memory (size: 24.0 B, free: 1918.1 MiB)
14:58:04.219 INFO  BlockManagerInfo - Removed broadcast_2001_piece0 on localhost:35475 in memory (size: 64.4 KiB, free: 1918.1 MiB)
14:58:04.219 INFO  BlockManagerInfo - Removed broadcast_1991_piece0 on localhost:35475 in memory (size: 4.1 KiB, free: 1918.1 MiB)
14:58:04.219 INFO  BlockManagerInfo - Removed broadcast_1963_piece0 on localhost:35475 in memory (size: 64.3 KiB, free: 1918.2 MiB)
14:58:04.220 INFO  BlockManagerInfo - Removed broadcast_1989_piece0 on localhost:35475 in memory (size: 64.4 KiB, free: 1918.3 MiB)
14:58:04.222 INFO  BlockManagerInfo - Removed broadcast_1978_piece0 on localhost:35475 in memory (size: 4.1 KiB, free: 1918.3 MiB)
14:58:04.223 INFO  BlockManagerInfo - Removed broadcast_1969_piece0 on localhost:35475 in memory (size: 13.2 KiB, free: 1918.3 MiB)
14:58:04.223 INFO  BlockManagerInfo - Removed broadcast_1970_piece0 on localhost:35475 in memory (size: 8.5 KiB, free: 1918.3 MiB)
14:58:04.223 INFO  BlockManagerInfo - Removed broadcast_1967_piece0 on localhost:35475 in memory (size: 31.0 B, free: 1918.3 MiB)
14:58:04.224 INFO  BlockManagerInfo - Removed broadcast_1979_piece0 on localhost:35475 in memory (size: 540.0 B, free: 1918.3 MiB)
14:58:04.224 INFO  BlockManagerInfo - Removed broadcast_1993_piece0 on localhost:35475 in memory (size: 21.0 B, free: 1918.3 MiB)
14:58:04.224 INFO  BlockManagerInfo - Removed broadcast_1997_piece0 on localhost:35475 in memory (size: 9.0 KiB, free: 1918.3 MiB)
14:58:04.225 INFO  BlockManagerInfo - Removed broadcast_1974_piece0 on localhost:35475 in memory (size: 72.1 KiB, free: 1918.4 MiB)
14:58:04.225 INFO  BlockManagerInfo - Removed broadcast_1995_piece0 on localhost:35475 in memory (size: 13.1 KiB, free: 1918.4 MiB)
14:58:04.225 INFO  BlockManagerInfo - Removed broadcast_1980_piece0 on localhost:35475 in memory (size: 209.0 B, free: 1918.4 MiB)
14:58:04.226 INFO  BlockManagerInfo - Removed broadcast_1959_piece0 on localhost:35475 in memory (size: 663.0 B, free: 1918.4 MiB)
14:58:04.226 INFO  BlockManagerInfo - Removed broadcast_1985_piece0 on localhost:35475 in memory (size: 7.9 KiB, free: 1918.4 MiB)
14:58:04.226 INFO  BlockManagerInfo - Removed broadcast_1971_piece0 on localhost:35475 in memory (size: 9.1 KiB, free: 1918.4 MiB)
14:58:04.227 INFO  BlockManagerInfo - Removed broadcast_1961_piece0 on localhost:35475 in memory (size: 72.1 KiB, free: 1918.5 MiB)
14:58:04.227 INFO  BlockManagerInfo - Removed broadcast_1972_piece0 on localhost:35475 in memory (size: 663.0 B, free: 1918.5 MiB)
14:58:04.227 INFO  BlockManagerInfo - Removed broadcast_1966_piece0 on localhost:35475 in memory (size: 19.0 B, free: 1918.5 MiB)
14:58:04.228 INFO  BlockManagerInfo - Removed broadcast_1964_piece0 on localhost:35475 in memory (size: 201.2 KiB, free: 1918.7 MiB)
14:58:04.228 INFO  BlockManagerInfo - Removed broadcast_1984_piece0 on localhost:35475 in memory (size: 18.0 KiB, free: 1918.7 MiB)
14:58:04.228 INFO  BlockManagerInfo - Removed broadcast_1982_piece0 on localhost:35475 in memory (size: 22.0 KiB, free: 1918.7 MiB)
14:58:04.228 INFO  BlockManagerInfo - Removed broadcast_1976_piece0 on localhost:35475 in memory (size: 64.4 KiB, free: 1918.8 MiB)
14:58:04.229 INFO  BlockManagerInfo - Removed broadcast_2000_piece0 on localhost:35475 in memory (size: 72.1 KiB, free: 1918.8 MiB)
14:58:04.230 INFO  BlockManagerInfo - Removed broadcast_1975_piece0 on localhost:35475 in memory (size: 64.4 KiB, free: 1918.9 MiB)
14:58:04.230 INFO  BlockManagerInfo - Removed broadcast_1981_piece0 on localhost:35475 in memory (size: 19.8 KiB, free: 1918.9 MiB)
14:58:04.231 INFO  BlockManagerInfo - Removed broadcast_1996_piece0 on localhost:35475 in memory (size: 8.3 KiB, free: 1918.9 MiB)
14:58:04.231 INFO  BlockManagerInfo - Removed broadcast_1986_piece0 on localhost:35475 in memory (size: 16.8 KiB, free: 1918.9 MiB)
14:58:04.231 INFO  BlockManagerInfo - Removed broadcast_1990_piece0 on localhost:35475 in memory (size: 201.1 KiB, free: 1919.1 MiB)
14:58:04.232 INFO  BlockManagerInfo - Removed broadcast_1994_piece0 on localhost:35475 in memory (size: 10.9 KiB, free: 1919.2 MiB)
14:58:04.232 INFO  BlockManagerInfo - Removed broadcast_1977_piece0 on localhost:35475 in memory (size: 210.1 KiB, free: 1919.4 MiB)
14:58:04.232 INFO  BlockManagerInfo - Removed broadcast_1987_piece0 on localhost:35475 in memory (size: 80.9 KiB, free: 1919.4 MiB)
14:58:04.233 INFO  BlockManagerInfo - Removed broadcast_1988_piece0 on localhost:35475 in memory (size: 64.4 KiB, free: 1919.5 MiB)
14:58:04.233 INFO  BlockManagerInfo - Removed broadcast_1999_piece0 on localhost:35475 in memory (size: 7.8 KiB, free: 1919.5 MiB)
14:58:04.233 INFO  BlockManagerInfo - Removed broadcast_1954_piece0 on localhost:35475 in memory (size: 31.0 B, free: 1919.5 MiB)
14:58:04.233 INFO  BlockManagerInfo - Removed broadcast_1962_piece0 on localhost:35475 in memory (size: 64.3 KiB, free: 1919.6 MiB)
14:58:04.234 INFO  BlockManagerInfo - Removed broadcast_1965_piece0 on localhost:35475 in memory (size: 4.1 KiB, free: 1919.6 MiB)
14:58:04.234 INFO  BlockManagerInfo - Removed broadcast_1983_piece0 on localhost:35475 in memory (size: 17.3 KiB, free: 1919.6 MiB)
14:58:04.235 INFO  BlockManagerInfo - Removed broadcast_1998_piece0 on localhost:35475 in memory (size: 500.0 B, free: 1919.6 MiB)
14:58:04.235 INFO  BlockManagerInfo - Removed broadcast_1953_piece0 on localhost:35475 in memory (size: 19.0 B, free: 1919.6 MiB)
14:58:04.235 INFO  BlockManagerInfo - Removed broadcast_1973_piece0 on localhost:35475 in memory (size: 8.0 KiB, free: 1919.6 MiB)
14:58:04.236 INFO  BlockManagerInfo - Removed broadcast_1968_piece0 on localhost:35475 in memory (size: 11.2 KiB, free: 1919.6 MiB)
14:58:04.244 INFO  MemoryStore - Block broadcast_2003 stored as values in memory (estimated size 481.4 KiB, free 1917.8 MiB)
14:58:04.247 INFO  MemoryStore - Block broadcast_2003_piece0 stored as bytes in memory (estimated size 207.4 KiB, free 1917.6 MiB)
14:58:04.247 INFO  BlockManagerInfo - Added broadcast_2003_piece0 in memory on localhost:35475 (size: 207.4 KiB, free: 1919.4 MiB)
14:58:04.247 INFO  SparkContext - Created broadcast 2003 from broadcast at DAGScheduler.scala:1580
14:58:04.247 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1242 (MapPartitionsRDD[5535] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:58:04.247 INFO  TaskSchedulerImpl - Adding task set 1242.0 with 1 tasks resource profile 0
14:58:04.248 INFO  TaskSetManager - Starting task 0.0 in stage 1242.0 (TID 1078) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9757 bytes) 
14:58:04.248 INFO  Executor - Running task 0.0 in stage 1242.0 (TID 1078)
14:58:04.277 INFO  NewHadoopRDD - Input split: file:/home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam:0+5416
14:58:04.282 INFO  Executor - Finished task 0.0 in stage 1242.0 (TID 1078). 1148 bytes result sent to driver
14:58:04.282 INFO  TaskSetManager - Finished task 0.0 in stage 1242.0 (TID 1078) in 34 ms on localhost (executor driver) (1/1)
14:58:04.282 INFO  TaskSchedulerImpl - Removed TaskSet 1242.0, whose tasks have all completed, from pool 
14:58:04.282 INFO  DAGScheduler - ShuffleMapStage 1242 (mapToPair at SparkUtils.java:161) finished in 0.069 s
14:58:04.282 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.282 INFO  DAGScheduler - running: HashSet()
14:58:04.282 INFO  DAGScheduler - waiting: HashSet(ResultStage 1243)
14:58:04.282 INFO  DAGScheduler - failed: HashSet()
14:58:04.282 INFO  DAGScheduler - Submitting ResultStage 1243 (MapPartitionsRDD[5538] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:58:04.283 INFO  MemoryStore - Block broadcast_2004 stored as values in memory (estimated size 7.4 KiB, free 1917.6 MiB)
14:58:04.283 INFO  MemoryStore - Block broadcast_2004_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1917.6 MiB)
14:58:04.283 INFO  BlockManagerInfo - Added broadcast_2004_piece0 in memory on localhost:35475 (size: 4.1 KiB, free: 1919.4 MiB)
14:58:04.283 INFO  SparkContext - Created broadcast 2004 from broadcast at DAGScheduler.scala:1580
14:58:04.283 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1243 (MapPartitionsRDD[5538] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:58:04.283 INFO  TaskSchedulerImpl - Adding task set 1243.0 with 1 tasks resource profile 0
14:58:04.284 INFO  TaskSetManager - Starting task 0.0 in stage 1243.0 (TID 1079) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:04.284 INFO  Executor - Running task 0.0 in stage 1243.0 (TID 1079)
14:58:04.285 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:58:04.285 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.286 INFO  Executor - Finished task 0.0 in stage 1243.0 (TID 1079). 2039 bytes result sent to driver
14:58:04.286 INFO  TaskSetManager - Finished task 0.0 in stage 1243.0 (TID 1079) in 2 ms on localhost (executor driver) (1/1)
14:58:04.286 INFO  TaskSchedulerImpl - Removed TaskSet 1243.0, whose tasks have all completed, from pool 
14:58:04.286 INFO  DAGScheduler - ResultStage 1243 (collect at SparkUtils.java:205) finished in 0.004 s
14:58:04.286 INFO  DAGScheduler - Job 565 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:04.286 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1243: Stage finished
14:58:04.286 INFO  DAGScheduler - Job 565 finished: collect at SparkUtils.java:205, took 0.074292 s
14:58:04.290 INFO  MemoryStore - Block broadcast_2005 stored as values in memory (estimated size 392.0 B, free 1917.6 MiB)
14:58:04.291 INFO  MemoryStore - Block broadcast_2005_piece0 stored as bytes in memory (estimated size 33.0 B, free 1917.6 MiB)
14:58:04.291 INFO  BlockManagerInfo - Added broadcast_2005_piece0 in memory on localhost:35475 (size: 33.0 B, free: 1919.4 MiB)
14:58:04.291 INFO  SparkContext - Created broadcast 2005 from broadcast at MarkDuplicatesSparkUtils.java:126
14:58:04.291 INFO  MemoryStore - Block broadcast_2006 stored as values in memory (estimated size 144.0 B, free 1917.6 MiB)
14:58:04.291 INFO  MemoryStore - Block broadcast_2006_piece0 stored as bytes in memory (estimated size 28.0 B, free 1917.6 MiB)
14:58:04.292 INFO  BlockManagerInfo - Added broadcast_2006_piece0 in memory on localhost:35475 (size: 28.0 B, free: 1919.4 MiB)
14:58:04.292 INFO  SparkContext - Created broadcast 2006 from broadcast at MarkDuplicatesSparkUtils.java:127
14:58:04.304 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:58:04.304 INFO  DAGScheduler - Registering RDD 5547 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 313
14:58:04.305 INFO  DAGScheduler - Registering RDD 5551 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 312
14:58:04.305 INFO  DAGScheduler - Registering RDD 5555 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 311
14:58:04.305 INFO  DAGScheduler - Got job 566 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:58:04.305 INFO  DAGScheduler - Final stage: ResultStage 1248 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:58:04.305 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1247)
14:58:04.305 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1247)
14:58:04.305 INFO  DAGScheduler - Submitting ShuffleMapStage 1245 (MapPartitionsRDD[5547] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:58:04.306 INFO  MemoryStore - Block broadcast_2007 stored as values in memory (estimated size 45.2 KiB, free 1917.6 MiB)
14:58:04.306 INFO  MemoryStore - Block broadcast_2007_piece0 stored as bytes in memory (estimated size 17.1 KiB, free 1917.5 MiB)
14:58:04.306 INFO  BlockManagerInfo - Added broadcast_2007_piece0 in memory on localhost:35475 (size: 17.1 KiB, free: 1919.4 MiB)
14:58:04.306 INFO  SparkContext - Created broadcast 2007 from broadcast at DAGScheduler.scala:1580
14:58:04.306 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1245 (MapPartitionsRDD[5547] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:58:04.307 INFO  TaskSchedulerImpl - Adding task set 1245.0 with 1 tasks resource profile 0
14:58:04.307 INFO  TaskSetManager - Starting task 0.0 in stage 1245.0 (TID 1080) (localhost, executor driver, partition 0, NODE_LOCAL, 9890 bytes) 
14:58:04.307 INFO  Executor - Running task 0.0 in stage 1245.0 (TID 1080)
14:58:04.308 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:58:04.308 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.311 INFO  Executor - Finished task 0.0 in stage 1245.0 (TID 1080). 1922 bytes result sent to driver
14:58:04.311 INFO  TaskSetManager - Finished task 0.0 in stage 1245.0 (TID 1080) in 4 ms on localhost (executor driver) (1/1)
14:58:04.311 INFO  TaskSchedulerImpl - Removed TaskSet 1245.0, whose tasks have all completed, from pool 
14:58:04.311 INFO  DAGScheduler - ShuffleMapStage 1245 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.006 s
14:58:04.311 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.311 INFO  DAGScheduler - running: HashSet()
14:58:04.311 INFO  DAGScheduler - waiting: HashSet(ResultStage 1248, ShuffleMapStage 1246, ShuffleMapStage 1247)
14:58:04.311 INFO  DAGScheduler - failed: HashSet()
14:58:04.311 INFO  DAGScheduler - Submitting ShuffleMapStage 1246 (MapPartitionsRDD[5551] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:58:04.312 INFO  MemoryStore - Block broadcast_2008 stored as values in memory (estimated size 49.3 KiB, free 1917.5 MiB)
14:58:04.312 INFO  MemoryStore - Block broadcast_2008_piece0 stored as bytes in memory (estimated size 19.3 KiB, free 1917.5 MiB)
14:58:04.312 INFO  BlockManagerInfo - Added broadcast_2008_piece0 in memory on localhost:35475 (size: 19.3 KiB, free: 1919.4 MiB)
14:58:04.312 INFO  SparkContext - Created broadcast 2008 from broadcast at DAGScheduler.scala:1580
14:58:04.313 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1246 (MapPartitionsRDD[5551] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:58:04.313 INFO  TaskSchedulerImpl - Adding task set 1246.0 with 1 tasks resource profile 0
14:58:04.313 INFO  TaskSetManager - Starting task 0.0 in stage 1246.0 (TID 1081) (localhost, executor driver, partition 0, NODE_LOCAL, 9365 bytes) 
14:58:04.313 INFO  Executor - Running task 0.0 in stage 1246.0 (TID 1081)
14:58:04.315 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:58:04.315 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.320 INFO  Executor - Finished task 0.0 in stage 1246.0 (TID 1081). 1922 bytes result sent to driver
14:58:04.320 INFO  TaskSetManager - Finished task 0.0 in stage 1246.0 (TID 1081) in 7 ms on localhost (executor driver) (1/1)
14:58:04.320 INFO  TaskSchedulerImpl - Removed TaskSet 1246.0, whose tasks have all completed, from pool 
14:58:04.320 INFO  DAGScheduler - ShuffleMapStage 1246 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
14:58:04.321 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.321 INFO  DAGScheduler - running: HashSet()
14:58:04.321 INFO  DAGScheduler - waiting: HashSet(ResultStage 1248, ShuffleMapStage 1247)
14:58:04.321 INFO  DAGScheduler - failed: HashSet()
14:58:04.321 INFO  DAGScheduler - Submitting ShuffleMapStage 1247 (MapPartitionsRDD[5555] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:58:04.321 INFO  MemoryStore - Block broadcast_2009 stored as values in memory (estimated size 40.0 KiB, free 1917.4 MiB)
14:58:04.322 INFO  MemoryStore - Block broadcast_2009_piece0 stored as bytes in memory (estimated size 14.5 KiB, free 1917.4 MiB)
14:58:04.322 INFO  BlockManagerInfo - Added broadcast_2009_piece0 in memory on localhost:35475 (size: 14.5 KiB, free: 1919.4 MiB)
14:58:04.322 INFO  SparkContext - Created broadcast 2009 from broadcast at DAGScheduler.scala:1580
14:58:04.322 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1247 (MapPartitionsRDD[5555] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:58:04.322 INFO  TaskSchedulerImpl - Adding task set 1247.0 with 1 tasks resource profile 0
14:58:04.322 INFO  TaskSetManager - Starting task 0.0 in stage 1247.0 (TID 1082) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:58:04.323 INFO  Executor - Running task 0.0 in stage 1247.0 (TID 1082)
14:58:04.324 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:58:04.324 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.326 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:58:04.326 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.327 INFO  Executor - Finished task 0.0 in stage 1247.0 (TID 1082). 1922 bytes result sent to driver
14:58:04.329 INFO  TaskSetManager - Finished task 0.0 in stage 1247.0 (TID 1082) in 7 ms on localhost (executor driver) (1/1)
14:58:04.329 INFO  TaskSchedulerImpl - Removed TaskSet 1247.0, whose tasks have all completed, from pool 
14:58:04.329 INFO  DAGScheduler - ShuffleMapStage 1247 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
14:58:04.329 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.329 INFO  DAGScheduler - running: HashSet()
14:58:04.329 INFO  DAGScheduler - waiting: HashSet(ResultStage 1248)
14:58:04.329 INFO  DAGScheduler - failed: HashSet()
14:58:04.329 INFO  DAGScheduler - Submitting ResultStage 1248 (MapPartitionsRDD[5557] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:58:04.330 INFO  MemoryStore - Block broadcast_2010 stored as values in memory (estimated size 41.2 KiB, free 1917.4 MiB)
14:58:04.330 INFO  MemoryStore - Block broadcast_2010_piece0 stored as bytes in memory (estimated size 15.3 KiB, free 1917.4 MiB)
14:58:04.331 INFO  BlockManagerInfo - Added broadcast_2010_piece0 in memory on localhost:35475 (size: 15.3 KiB, free: 1919.3 MiB)
14:58:04.331 INFO  SparkContext - Created broadcast 2010 from broadcast at DAGScheduler.scala:1580
14:58:04.331 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1248 (MapPartitionsRDD[5557] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:58:04.331 INFO  TaskSchedulerImpl - Adding task set 1248.0 with 1 tasks resource profile 0
14:58:04.331 INFO  TaskSetManager - Starting task 0.0 in stage 1248.0 (TID 1083) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:04.331 INFO  Executor - Running task 0.0 in stage 1248.0 (TID 1083)
14:58:04.333 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:58:04.333 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.334 INFO  Executor - Finished task 0.0 in stage 1248.0 (TID 1083). 1944 bytes result sent to driver
14:58:04.334 INFO  TaskSetManager - Finished task 0.0 in stage 1248.0 (TID 1083) in 3 ms on localhost (executor driver) (1/1)
14:58:04.334 INFO  TaskSchedulerImpl - Removed TaskSet 1248.0, whose tasks have all completed, from pool 
14:58:04.334 INFO  DAGScheduler - ResultStage 1248 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
14:58:04.334 INFO  DAGScheduler - Job 566 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:04.334 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1248: Stage finished
14:58:04.334 INFO  DAGScheduler - Job 566 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.030143 s
14:58:04.345 INFO  MemoryStore - Block broadcast_2011 stored as values in memory (estimated size 93.5 KiB, free 1917.3 MiB)
14:58:04.346 INFO  MemoryStore - Block broadcast_2011_piece0 stored as bytes in memory (estimated size 5.6 KiB, free 1917.3 MiB)
14:58:04.346 INFO  BlockManagerInfo - Added broadcast_2011_piece0 in memory on localhost:35475 (size: 5.6 KiB, free: 1919.3 MiB)
14:58:04.346 INFO  SparkContext - Created broadcast 2011 from broadcast at ReadsSparkSink.java:133
14:58:04.349 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:58:04.349 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:58:04.349 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:58:04.365 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:58:04.366 INFO  DAGScheduler - Registering RDD 5559 (mapToPair at SparkUtils.java:161) as input to shuffle 314
14:58:04.366 INFO  DAGScheduler - Got job 567 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:58:04.366 INFO  DAGScheduler - Final stage: ResultStage 1253 (runJob at SparkHadoopWriter.scala:83)
14:58:04.366 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1252)
14:58:04.366 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1252)
14:58:04.366 INFO  DAGScheduler - Submitting ShuffleMapStage 1252 (MapPartitionsRDD[5559] at mapToPair at SparkUtils.java:161), which has no missing parents
14:58:04.367 INFO  MemoryStore - Block broadcast_2012 stored as values in memory (estimated size 39.1 KiB, free 1917.2 MiB)
14:58:04.367 INFO  MemoryStore - Block broadcast_2012_piece0 stored as bytes in memory (estimated size 14.1 KiB, free 1917.2 MiB)
14:58:04.367 INFO  BlockManagerInfo - Added broadcast_2012_piece0 in memory on localhost:35475 (size: 14.1 KiB, free: 1919.3 MiB)
14:58:04.368 INFO  SparkContext - Created broadcast 2012 from broadcast at DAGScheduler.scala:1580
14:58:04.368 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1252 (MapPartitionsRDD[5559] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:58:04.368 INFO  TaskSchedulerImpl - Adding task set 1252.0 with 1 tasks resource profile 0
14:58:04.368 INFO  TaskSetManager - Starting task 0.0 in stage 1252.0 (TID 1084) (localhost, executor driver, partition 0, NODE_LOCAL, 9948 bytes) 
14:58:04.368 INFO  Executor - Running task 0.0 in stage 1252.0 (TID 1084)
14:58:04.370 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:58:04.370 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.371 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:58:04.371 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.372 INFO  Executor - Finished task 0.0 in stage 1252.0 (TID 1084). 1922 bytes result sent to driver
14:58:04.372 INFO  TaskSetManager - Finished task 0.0 in stage 1252.0 (TID 1084) in 4 ms on localhost (executor driver) (1/1)
14:58:04.372 INFO  TaskSchedulerImpl - Removed TaskSet 1252.0, whose tasks have all completed, from pool 
14:58:04.372 INFO  DAGScheduler - ShuffleMapStage 1252 (mapToPair at SparkUtils.java:161) finished in 0.006 s
14:58:04.372 INFO  DAGScheduler - looking for newly runnable stages
14:58:04.372 INFO  DAGScheduler - running: HashSet()
14:58:04.372 INFO  DAGScheduler - waiting: HashSet(ResultStage 1253)
14:58:04.372 INFO  DAGScheduler - failed: HashSet()
14:58:04.373 INFO  DAGScheduler - Submitting ResultStage 1253 (MapPartitionsRDD[5565] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:58:04.379 INFO  MemoryStore - Block broadcast_2013 stored as values in memory (estimated size 184.3 KiB, free 1917.0 MiB)
14:58:04.380 INFO  MemoryStore - Block broadcast_2013_piece0 stored as bytes in memory (estimated size 78.3 KiB, free 1917.0 MiB)
14:58:04.380 INFO  BlockManagerInfo - Added broadcast_2013_piece0 in memory on localhost:35475 (size: 78.3 KiB, free: 1919.2 MiB)
14:58:04.380 INFO  SparkContext - Created broadcast 2013 from broadcast at DAGScheduler.scala:1580
14:58:04.380 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1253 (MapPartitionsRDD[5565] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
14:58:04.380 INFO  TaskSchedulerImpl - Adding task set 1253.0 with 1 tasks resource profile 0
14:58:04.380 INFO  TaskSetManager - Starting task 0.0 in stage 1253.0 (TID 1085) (localhost, executor driver, partition 0, NODE_LOCAL, 9376 bytes) 
14:58:04.380 INFO  Executor - Running task 0.0 in stage 1253.0 (TID 1085)
14:58:04.384 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:58:04.384 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:58:04.385 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:58:04.385 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:58:04.385 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:58:04.395 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271458043825536257808989513_5565_m_000000_0' to file:/tmp/MarkDups16546143401850284688/MarkDups.sam.parts/_temporary/0/task_202505271458043825536257808989513_5565_m_000000
14:58:04.395 INFO  SparkHadoopMapRedUtil - attempt_202505271458043825536257808989513_5565_m_000000_0: Committed. Elapsed time: 0 ms.
14:58:04.396 INFO  Executor - Finished task 0.0 in stage 1253.0 (TID 1085). 1858 bytes result sent to driver
14:58:04.396 INFO  TaskSetManager - Finished task 0.0 in stage 1253.0 (TID 1085) in 16 ms on localhost (executor driver) (1/1)
14:58:04.396 INFO  TaskSchedulerImpl - Removed TaskSet 1253.0, whose tasks have all completed, from pool 
14:58:04.396 INFO  DAGScheduler - ResultStage 1253 (runJob at SparkHadoopWriter.scala:83) finished in 0.023 s
14:58:04.396 INFO  DAGScheduler - Job 567 is finished. Cancelling potential speculative or zombie tasks for this job
14:58:04.396 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1253: Stage finished
14:58:04.396 INFO  DAGScheduler - Job 567 finished: runJob at SparkHadoopWriter.scala:83, took 0.030618 s
14:58:04.396 INFO  SparkHadoopWriter - Start to commit write Job job_202505271458043825536257808989513_5565.
14:58:04.400 INFO  SparkHadoopWriter - Write Job job_202505271458043825536257808989513_5565 committed. Elapsed time: 3 ms.
14:58:04.407 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups16546143401850284688/MarkDups.sam
14:58:04.411 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups16546143401850284688/MarkDups.sam done
14:58:04.411 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:58:04 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:04 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:05 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:06 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:06 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:06 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:07 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:07 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:07 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:08 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:09 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:09 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:09 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
14:58:10.027 ERROR Executor - Exception in task 0.0 in stage 1473.0 (TID 1232)
org.broadinstitute.hellbender.exceptions.UserException$ReadMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 is missing the read group (RG) tag, which is required by the GATK.  Please use http://gatkforums.broadinstitute.org/discussion/59/companion-utilities-replacereadgroups to fix this problem
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:64) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[main/:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[main/:?]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[main/:?]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[scala-library-2.13.14.jar:?]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[scala-library-2.13.14.jar:?]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [spark-core_2.13-3.5.0.jar:3.5.0]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:833) [?:?]
14:58:10.044 ERROR TaskSetManager - Task 0 in stage 1473.0 failed 1 times; aborting job
[May 27, 2025 at 2:58:10 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
14:58:10.258 ERROR Executor - Exception in task 0.0 in stage 1480.0 (TID 1235)
org.broadinstitute.hellbender.exceptions.UserException$HeaderMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 contains an (RG) tag with the group NotADuplicateGroup which is not found in the file header.
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:66) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[main/:?]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[main/:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[main/:?]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[main/:?]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[scala-library-2.13.14.jar:?]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[scala-library-2.13.14.jar:?]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[spark-common-utils_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[spark-core_2.13-3.5.0.jar:3.5.0]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [spark-core_2.13-3.5.0.jar:3.5.0]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:833) [?:?]
14:58:10.260 ERROR TaskSetManager - Task 0 in stage 1480.0 failed 1 times; aborting job
[May 27, 2025 at 2:58:10 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:10 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:10 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:11 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:11 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:11 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:12 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:13 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:13 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:13 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:14 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:14 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:14 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:15 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:16 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:16 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:16 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:17 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:17 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:17 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:18 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:18 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:18 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:18 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:19 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:19 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:19 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:20 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:20 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:20 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:21 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:21 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:21 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:21 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:22 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:22 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:22 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:23 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:23 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:23 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:24 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:24 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:24 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:24 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:25 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:25 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:25 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:26 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:26 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:26 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:27 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:28 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:28 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:28 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:29 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:29 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:29 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:30 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:31 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:31 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:31 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:32 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:32 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:32 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:33 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:34 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280
[May 27, 2025 at 2:58:34 PM UTC] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1342177280