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

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

tests
0

failures
0

ignored
1m0.61s

duration
100%

successful

Tests

Test Duration Result
assertThatExpectedOutputUpdateToggleIsDisabled 0s passed
testAssertAssumeUnsortedFilesAreQueryGroupedFiles 0.784s passed
testAssertCorrectSortOrderMultipleBams 0.143s passed
testAssertCorrectSortOrderMultipleBamsOverriding 0.474s passed
testBulkFragmentsNoDuplicates 1.032s passed
testBulkFragmentsWithDuplicates 2.095s passed
testDifferentChromosomesInOppositeOrder 0.304s 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.293s 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.253s passed
testDuplicateDetectionDataProviderWithMetrics[2](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.picard-2.15.0.sorted.inputSingleLibrarySolexa16404.metrics) 0.252s passed
testFlowModeFlag 1.517s passed
testHashCollisionHandling 1.057s 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.292s 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.275s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[0](true, true, true) 0.299s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[1](true, false, true) 0.310s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[2](false, true, true) 0.306s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[3](true, true, false) 0.324s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[4](true, false, false) 0.314s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[5](false, true, false) 0.309s passed
testMappedFragmentAndMappedPairFirstOfPairNonPrimary 0.301s passed
testMappedFragmentAndMatePairFirstUnmapped 0.303s passed
testMappedFragmentAndMatePairSecondUnmapped 0.294s passed
testMappedPairAndMappedFragmentAndMatePairFirstUnmapped 0.301s passed
testMappedPairAndMappedFragmentAndMatePairSecondUnmapped 0.342s passed
testMappedPairAndMatePairFirstOppositeStrandSecondUnmapped 0.301s passed
testMappedPairAndMatePairFirstUnmapped 0.296s passed
testMappedPairAndMatePairSecondUnmapped 0.293s passed
testMappedPairWithFirstEndSamePositionAndOther 0.309s passed
testMappedPairWithSamePosition 0.297s passed
testMappedPairWithSamePositionSameCigar 0.297s passed
testMarkDuplicatesSparkDeletingDuplicateReads[0]([Ljava.io.File;@238e1c20, 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;@23c1b5b3, 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.361s passed
testMarkDuplicatesSparkDeletingDuplicateReads[2]([Ljava.io.File;@220cb217, 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.370s passed
testMarkDuplicatesSparkDeletingDuplicateReads[3]([Ljava.io.File;@48ac495d, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.336s passed
testMarkDuplicatesSparkDeletingDuplicateReads[4]([Ljava.io.File;@1a8cf2bc, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.335s passed
testMarkDuplicatesSparkDeletingDuplicateReads[5]([Ljava.io.File;@29b08305, 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.261s passed
testMarkDuplicatesSparkDeletingDuplicateReads[6]([Ljava.io.File;@22f3e7cd, 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.231s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[0]([Ljava.io.File;@3883c230, 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.366s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[1]([Ljava.io.File;@7f639161, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.383s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[2]([Ljava.io.File;@10d63564, 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.405s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[3]([Ljava.io.File;@1ce3f193, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.414s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[4]([Ljava.io.File;@5ab728c2, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.319s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[5]([Ljava.io.File;@4d545c5, 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.154s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[6]([Ljava.io.File;@6754f918, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 1.177s passed
testMarkDuplicatesSparkIntegrationTestLocal[0]([Ljava.io.File;@92b1413, 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.340s passed
testMarkDuplicatesSparkIntegrationTestLocal[1]([Ljava.io.File;@5bff8647, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.359s passed
testMarkDuplicatesSparkIntegrationTestLocal[2]([Ljava.io.File;@7d2b6642, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.381s passed
testMarkDuplicatesSparkIntegrationTestLocal[3]([Ljava.io.File;@1e278118, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.323s passed
testMarkDuplicatesSparkIntegrationTestLocal[4]([Ljava.io.File;@476e9f60, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.339s passed
testMarkDuplicatesSparkIntegrationTestLocal[5]([Ljava.io.File;@775647cd, 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.186s passed
testMarkDuplicatesSparkIntegrationTestLocal[6]([Ljava.io.File;@25d72de7, 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.182s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[0]([Ljava.io.File;@7c240d54, 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
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[1]([Ljava.io.File;@66ac901d, 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
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[2]([Ljava.io.File;@2a88bb75, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.367s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[3]([Ljava.io.File;@df1f0c5, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.314s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[4]([Ljava.io.File;@791f270d, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.324s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[5]([Ljava.io.File;@478ad00f, 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.233s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[6]([Ljava.io.File;@5ce9bd35, 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.144s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[0]([Ljava.io.File;@2564a80d, 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.337s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[1]([Ljava.io.File;@7f212d2d, 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
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[2]([Ljava.io.File;@1e1fa89f, 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
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[3]([Ljava.io.File;@6d90d5d9, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.368s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[4]([Ljava.io.File;@4a7a4d1c, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.346s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[5]([Ljava.io.File;@4f6c1165, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 1.166s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[6]([Ljava.io.File;@711bb1a2, 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.115s passed
testMatePairFirstUnmapped 0.303s passed
testMatePairSecondUnmapped 0.302s passed
testNoReadGroupInRead 0.243s passed
testNonExistantReadGroupInRead 0.235s passed
testNullOpticalDuplicates 0.323s passed
testOpticalDuplicateClusterOneEndSamePositionOneCluster 0.312s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicatesWithinPixelDistance 0.305s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.307s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.294s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.305s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.294s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.300s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.309s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.297s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.300s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.313s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.297s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.297s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.314s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.304s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.298s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.320s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.312s passed
testOpticalDuplicateClusterSamePositionOneOpticalDuplicatesWithinPixelDistance 0.309s passed
testOpticalDuplicateClustersAddingSecondEndFirstSameCoordinate 0.296s passed
testOpticalDuplicateFinding 0.299s passed
testOpticalDuplicateFindingPxelDistance 0.308s passed
testOpticalDuplicatesAndPCRDuplicatesOrientationDifference 0.295s passed
testOpticalDuplicatesDifferentReadGroups 0.300s passed
testOpticalDuplicatesTheSameReadGroup 0.307s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.298s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.305s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.316s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.292s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.300s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.314s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.293s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.307s 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.296s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.303s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.310s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.291s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.293s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.308s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.298s passed
testPathologicalOrderingAtTheSamePosition 0.292s passed
testReadSameStartPositionOrientationOverride 0.347s passed
testReadsHaveSameStartPositionButDifferentChromosomeNonEquivalence 0.293s passed
testSecondEndIsBeforeFirstInCoordinate 0.302s passed
testSingleMappedFragment 0.299s passed
testSingleMappedFragmentAndSingleMappedPair 0.294s passed
testSingleMappedFragmentAndTwoMappedPairs 0.292s passed
testSingleMappedPair 0.315s passed
testSingleUnmappedFragment 0.300s passed
testSingleUnmappedPair 0.292s passed
testStackOverFlowPairSetSwap 0.307s passed
testSupplementaryReadUnmappedMate 0.294s passed
testThreeGroupsOnDifferentChromosomesOfThreeMappedPairs 0.293s passed
testThreeMappedPairs 0.307s passed
testThreeMappedPairsWithMatchingSecondMate 0.297s passed
testTwoGroupsOnDifferentChromosomesOfThreeMappedPairs 0.293s passed
testTwoGroupsOnDifferentChromosomesOfTwoFragments 0.321s passed
testTwoGroupsOnDifferentChromosomesOfTwoMappedPairs 0.327s passed
testTwoMappedFragments 0.296s passed
testTwoMappedPairWithSamePosition 0.310s passed
testTwoMappedPairWithSamePositionDifferentStrands 0.294s passed
testTwoMappedPairWithSamePositionDifferentStrands2 0.288s passed
testTwoMappedPairs 0.302s passed
testTwoMappedPairsAndMappedSecondaryFragment 0.300s passed
testTwoMappedPairsAndTerminalUnmappedFragment 0.303s passed
testTwoMappedPairsAndTerminalUnmappedPair 0.322s passed
testTwoMappedPairsMatesSoftClipped 0.302s passed
testTwoMappedPairsWithOppositeOrientations 0.294s passed
testTwoMappedPairsWithOppositeOrientationsNumberTwo 0.306s passed
testTwoMappedPairsWithSoftClipping 0.298s passed
testTwoMappedPairsWithSoftClippingBoth 0.306s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnly 0.305s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnlyNoMateCigar 0.300s passed
testTwoMappedPairsWithSupplementaryReads[0](true, true, true) 0.305s passed
testTwoMappedPairsWithSupplementaryReads[1](true, false, true) 0.305s passed
testTwoMappedPairsWithSupplementaryReads[2](false, true, true) 0.292s passed
testTwoMappedPairsWithSupplementaryReads[3](true, true, false) 0.290s passed
testTwoMappedPairsWithSupplementaryReads[4](true, false, false) 0.307s passed
testTwoMappedPairsWithSupplementaryReads[5](false, true, false) 0.290s passed
testTwoUnmappedFragments 0.290s passed

Standard error

[May 27, 2025 at 2:04:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:49 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
14:04:52.059 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:04:52.059 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5c95f6f-SNAPSHOT
14:04:52.059 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:04:52.059 INFO  MarkDuplicatesSpark - Executing as root@9cd1444b9593 on Linux v6.11.0-1014-azure amd64
14:04:52.059 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:04:52.059 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:04:52 PM GMT
14:04:52.059 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:04:52.059 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:04:52.060 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:04:52.060 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:04:52.060 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:04:52.060 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:04:52.060 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:04:52.060 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:04:52.060 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:04:52.060 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:04:52.060 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:04:52.060 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:04:52.060 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:04:52.060 INFO  MarkDuplicatesSpark - Initializing engine
14:04:52.060 INFO  MarkDuplicatesSpark - Done initializing engine
14:04:52.060 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:04:52.063 INFO  MemoryStore - Block broadcast_1411 stored as values in memory (estimated size 305.5 KiB, free 1898.4 MiB)
14:04:52.069 INFO  MemoryStore - Block broadcast_1411_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1898.4 MiB)
14:04:52.070 INFO  BlockManagerInfo - Added broadcast_1411_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.7 MiB)
14:04:52.070 INFO  SparkContext - Created broadcast 1411 from newAPIHadoopFile at PathSplitSource.java:96
14:04:52.090 INFO  MemoryStore - Block broadcast_1412 stored as values in memory (estimated size 305.5 KiB, free 1898.1 MiB)
14:04:52.096 INFO  MemoryStore - Block broadcast_1412_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1898.0 MiB)
14:04:52.096 INFO  BlockManagerInfo - Added broadcast_1412_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.6 MiB)
14:04:52.097 INFO  SparkContext - Created broadcast 1412 from newAPIHadoopFile at PathSplitSource.java:96
14:04:52.128 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:04:52.128 INFO  FileInputFormat - Total input files to process : 1
14:04:52.129 INFO  DAGScheduler - Registering RDD 3614 (mapToPair at SparkUtils.java:161) as input to shuffle 97
14:04:52.129 INFO  DAGScheduler - Got job 433 (collect at SparkUtils.java:205) with 1 output partitions
14:04:52.129 INFO  DAGScheduler - Final stage: ResultStage 741 (collect at SparkUtils.java:205)
14:04:52.130 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 740)
14:04:52.130 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 740)
14:04:52.130 INFO  DAGScheduler - Submitting ShuffleMapStage 740 (MapPartitionsRDD[3614] at mapToPair at SparkUtils.java:161), which has no missing parents
14:04:52.147 INFO  MemoryStore - Block broadcast_1413 stored as values in memory (estimated size 459.2 KiB, free 1897.6 MiB)
14:04:52.149 INFO  MemoryStore - Block broadcast_1413_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1897.4 MiB)
14:04:52.149 INFO  BlockManagerInfo - Added broadcast_1413_piece0 in memory on localhost:46769 (size: 201.4 KiB, free: 1918.4 MiB)
14:04:52.150 INFO  SparkContext - Created broadcast 1413 from broadcast at DAGScheduler.scala:1580
14:04:52.150 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 740 (MapPartitionsRDD[3614] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:04:52.150 INFO  TaskSchedulerImpl - Adding task set 740.0 with 1 tasks resource profile 0
14:04:52.151 INFO  TaskSetManager - Starting task 0.0 in stage 740.0 (TID 670) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9650 bytes) 
14:04:52.152 INFO  Executor - Running task 0.0 in stage 740.0 (TID 670)
14:04:52.180 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam:0+1507
14:04:52.184 INFO  Executor - Finished task 0.0 in stage 740.0 (TID 670). 1148 bytes result sent to driver
14:04:52.185 INFO  TaskSetManager - Finished task 0.0 in stage 740.0 (TID 670) in 35 ms on localhost (executor driver) (1/1)
14:04:52.185 INFO  TaskSchedulerImpl - Removed TaskSet 740.0, whose tasks have all completed, from pool 
14:04:52.185 INFO  DAGScheduler - ShuffleMapStage 740 (mapToPair at SparkUtils.java:161) finished in 0.055 s
14:04:52.185 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.185 INFO  DAGScheduler - running: HashSet()
14:04:52.185 INFO  DAGScheduler - waiting: HashSet(ResultStage 741)
14:04:52.185 INFO  DAGScheduler - failed: HashSet()
14:04:52.186 INFO  DAGScheduler - Submitting ResultStage 741 (MapPartitionsRDD[3617] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:04:52.186 INFO  MemoryStore - Block broadcast_1414 stored as values in memory (estimated size 7.4 KiB, free 1897.4 MiB)
14:04:52.187 INFO  MemoryStore - Block broadcast_1414_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1897.4 MiB)
14:04:52.187 INFO  BlockManagerInfo - Added broadcast_1414_piece0 in memory on localhost:46769 (size: 4.1 KiB, free: 1918.4 MiB)
14:04:52.187 INFO  SparkContext - Created broadcast 1414 from broadcast at DAGScheduler.scala:1580
14:04:52.187 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 741 (MapPartitionsRDD[3617] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:04:52.187 INFO  TaskSchedulerImpl - Adding task set 741.0 with 1 tasks resource profile 0
14:04:52.188 INFO  TaskSetManager - Starting task 0.0 in stage 741.0 (TID 671) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:04:52.188 INFO  Executor - Running task 0.0 in stage 741.0 (TID 671)
14:04:52.189 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:04:52.189 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.191 INFO  Executor - Finished task 0.0 in stage 741.0 (TID 671). 2238 bytes result sent to driver
14:04:52.192 INFO  TaskSetManager - Finished task 0.0 in stage 741.0 (TID 671) in 4 ms on localhost (executor driver) (1/1)
14:04:52.192 INFO  TaskSchedulerImpl - Removed TaskSet 741.0, whose tasks have all completed, from pool 
14:04:52.192 INFO  DAGScheduler - ResultStage 741 (collect at SparkUtils.java:205) finished in 0.006 s
14:04:52.192 INFO  DAGScheduler - Job 433 is finished. Cancelling potential speculative or zombie tasks for this job
14:04:52.192 INFO  TaskSchedulerImpl - Killing all running tasks in stage 741: Stage finished
14:04:52.192 INFO  DAGScheduler - Job 433 finished: collect at SparkUtils.java:205, took 0.064224 s
14:04:52.197 INFO  MemoryStore - Block broadcast_1415 stored as values in memory (estimated size 1632.0 B, free 1897.4 MiB)
14:04:52.197 INFO  MemoryStore - Block broadcast_1415_piece0 stored as bytes in memory (estimated size 145.0 B, free 1897.4 MiB)
14:04:52.197 INFO  BlockManagerInfo - Added broadcast_1415_piece0 in memory on localhost:46769 (size: 145.0 B, free: 1918.4 MiB)
14:04:52.198 INFO  SparkContext - Created broadcast 1415 from broadcast at MarkDuplicatesSparkUtils.java:126
14:04:52.198 INFO  MemoryStore - Block broadcast_1416 stored as values in memory (estimated size 304.0 B, free 1897.4 MiB)
14:04:52.198 INFO  MemoryStore - Block broadcast_1416_piece0 stored as bytes in memory (estimated size 37.0 B, free 1897.4 MiB)
14:04:52.198 INFO  BlockManagerInfo - Added broadcast_1416_piece0 in memory on localhost:46769 (size: 37.0 B, free: 1918.4 MiB)
14:04:52.199 INFO  SparkContext - Created broadcast 1416 from broadcast at MarkDuplicatesSparkUtils.java:127
14:04:52.211 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:04:52.211 INFO  DAGScheduler - Registering RDD 3626 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 100
14:04:52.211 INFO  DAGScheduler - Registering RDD 3630 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 99
14:04:52.212 INFO  DAGScheduler - Registering RDD 3634 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 98
14:04:52.212 INFO  DAGScheduler - Got job 434 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:04:52.212 INFO  DAGScheduler - Final stage: ResultStage 746 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:04:52.212 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 745)
14:04:52.212 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 745)
14:04:52.212 INFO  DAGScheduler - Submitting ShuffleMapStage 743 (MapPartitionsRDD[3626] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:04:52.213 INFO  MemoryStore - Block broadcast_1417 stored as values in memory (estimated size 24.2 KiB, free 1897.3 MiB)
14:04:52.214 INFO  MemoryStore - Block broadcast_1417_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1897.3 MiB)
14:04:52.214 INFO  BlockManagerInfo - Added broadcast_1417_piece0 in memory on localhost:46769 (size: 12.6 KiB, free: 1918.4 MiB)
14:04:52.214 INFO  SparkContext - Created broadcast 1417 from broadcast at DAGScheduler.scala:1580
14:04:52.214 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 743 (MapPartitionsRDD[3626] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:04:52.214 INFO  TaskSchedulerImpl - Adding task set 743.0 with 1 tasks resource profile 0
14:04:52.215 INFO  TaskSetManager - Starting task 0.0 in stage 743.0 (TID 672) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:04:52.215 INFO  Executor - Running task 0.0 in stage 743.0 (TID 672)
14:04:52.217 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:04:52.218 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.221 INFO  Executor - Finished task 0.0 in stage 743.0 (TID 672). 1922 bytes result sent to driver
14:04:52.222 INFO  TaskSetManager - Finished task 0.0 in stage 743.0 (TID 672) in 7 ms on localhost (executor driver) (1/1)
14:04:52.222 INFO  TaskSchedulerImpl - Removed TaskSet 743.0, whose tasks have all completed, from pool 
14:04:52.222 INFO  DAGScheduler - ShuffleMapStage 743 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.009 s
14:04:52.222 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.222 INFO  DAGScheduler - running: HashSet()
14:04:52.222 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 744, ShuffleMapStage 745, ResultStage 746)
14:04:52.222 INFO  DAGScheduler - failed: HashSet()
14:04:52.223 INFO  DAGScheduler - Submitting ShuffleMapStage 744 (MapPartitionsRDD[3630] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:04:52.224 INFO  MemoryStore - Block broadcast_1418 stored as values in memory (estimated size 28.3 KiB, free 1897.3 MiB)
14:04:52.224 INFO  MemoryStore - Block broadcast_1418_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1897.3 MiB)
14:04:52.224 INFO  BlockManagerInfo - Added broadcast_1418_piece0 in memory on localhost:46769 (size: 14.8 KiB, free: 1918.4 MiB)
14:04:52.225 INFO  SparkContext - Created broadcast 1418 from broadcast at DAGScheduler.scala:1580
14:04:52.225 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 744 (MapPartitionsRDD[3630] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:04:52.225 INFO  TaskSchedulerImpl - Adding task set 744.0 with 1 tasks resource profile 0
14:04:52.225 INFO  TaskSetManager - Starting task 0.0 in stage 744.0 (TID 673) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:04:52.226 INFO  Executor - Running task 0.0 in stage 744.0 (TID 673)
14:04:52.228 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:04:52.228 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.233 INFO  Executor - Finished task 0.0 in stage 744.0 (TID 673). 1922 bytes result sent to driver
14:04:52.233 INFO  TaskSetManager - Finished task 0.0 in stage 744.0 (TID 673) in 8 ms on localhost (executor driver) (1/1)
14:04:52.233 INFO  TaskSchedulerImpl - Removed TaskSet 744.0, whose tasks have all completed, from pool 
14:04:52.233 INFO  DAGScheduler - ShuffleMapStage 744 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.010 s
14:04:52.233 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.233 INFO  DAGScheduler - running: HashSet()
14:04:52.233 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 745, ResultStage 746)
14:04:52.233 INFO  DAGScheduler - failed: HashSet()
14:04:52.234 INFO  DAGScheduler - Submitting ShuffleMapStage 745 (MapPartitionsRDD[3634] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:04:52.234 INFO  MemoryStore - Block broadcast_1419 stored as values in memory (estimated size 19.0 KiB, free 1897.3 MiB)
14:04:52.235 INFO  MemoryStore - Block broadcast_1419_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1897.2 MiB)
14:04:52.235 INFO  BlockManagerInfo - Added broadcast_1419_piece0 in memory on localhost:46769 (size: 9.7 KiB, free: 1918.4 MiB)
14:04:52.235 INFO  SparkContext - Created broadcast 1419 from broadcast at DAGScheduler.scala:1580
14:04:52.236 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 745 (MapPartitionsRDD[3634] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:04:52.236 INFO  TaskSchedulerImpl - Adding task set 745.0 with 1 tasks resource profile 0
14:04:52.236 INFO  TaskSetManager - Starting task 0.0 in stage 745.0 (TID 674) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:04:52.237 INFO  Executor - Running task 0.0 in stage 745.0 (TID 674)
14:04:52.239 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:04:52.239 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.241 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:04:52.241 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.243 INFO  Executor - Finished task 0.0 in stage 745.0 (TID 674). 1922 bytes result sent to driver
14:04:52.244 INFO  TaskSetManager - Finished task 0.0 in stage 745.0 (TID 674) in 7 ms on localhost (executor driver) (1/1)
14:04:52.244 INFO  TaskSchedulerImpl - Removed TaskSet 745.0, whose tasks have all completed, from pool 
14:04:52.244 INFO  DAGScheduler - ShuffleMapStage 745 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.010 s
14:04:52.244 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.244 INFO  DAGScheduler - running: HashSet()
14:04:52.244 INFO  DAGScheduler - waiting: HashSet(ResultStage 746)
14:04:52.244 INFO  DAGScheduler - failed: HashSet()
14:04:52.244 INFO  DAGScheduler - Submitting ResultStage 746 (MapPartitionsRDD[3636] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:04:52.245 INFO  MemoryStore - Block broadcast_1420 stored as values in memory (estimated size 20.2 KiB, free 1897.2 MiB)
14:04:52.246 INFO  MemoryStore - Block broadcast_1420_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1897.2 MiB)
14:04:52.246 INFO  BlockManagerInfo - Added broadcast_1420_piece0 in memory on localhost:46769 (size: 10.6 KiB, free: 1918.4 MiB)
14:04:52.246 INFO  SparkContext - Created broadcast 1420 from broadcast at DAGScheduler.scala:1580
14:04:52.246 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 746 (MapPartitionsRDD[3636] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:04:52.246 INFO  TaskSchedulerImpl - Adding task set 746.0 with 1 tasks resource profile 0
14:04:52.247 INFO  TaskSetManager - Starting task 0.0 in stage 746.0 (TID 675) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:04:52.247 INFO  Executor - Running task 0.0 in stage 746.0 (TID 675)
14:04:52.248 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:04:52.249 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.251 INFO  Executor - Finished task 0.0 in stage 746.0 (TID 675). 1944 bytes result sent to driver
14:04:52.251 INFO  TaskSetManager - Finished task 0.0 in stage 746.0 (TID 675) in 4 ms on localhost (executor driver) (1/1)
14:04:52.251 INFO  TaskSchedulerImpl - Removed TaskSet 746.0, whose tasks have all completed, from pool 
14:04:52.251 INFO  DAGScheduler - ResultStage 746 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.007 s
14:04:52.251 INFO  DAGScheduler - Job 434 is finished. Cancelling potential speculative or zombie tasks for this job
14:04:52.251 INFO  TaskSchedulerImpl - Killing all running tasks in stage 746: Stage finished
14:04:52.251 INFO  DAGScheduler - Job 434 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.040609 s
14:04:52.261 INFO  MemoryStore - Block broadcast_1421 stored as values in memory (estimated size 20.3 KiB, free 1897.2 MiB)
14:04:52.262 INFO  MemoryStore - Block broadcast_1421_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1897.2 MiB)
14:04:52.262 INFO  BlockManagerInfo - Added broadcast_1421_piece0 in memory on localhost:46769 (size: 1850.0 B, free: 1918.4 MiB)
14:04:52.262 INFO  SparkContext - Created broadcast 1421 from broadcast at ReadsSparkSink.java:133
14:04:52.263 INFO  MemoryStore - Block broadcast_1422 stored as values in memory (estimated size 20.4 KiB, free 1897.2 MiB)
14:04:52.263 INFO  MemoryStore - Block broadcast_1422_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1897.2 MiB)
14:04:52.264 INFO  BlockManagerInfo - Added broadcast_1422_piece0 in memory on localhost:46769 (size: 1850.0 B, free: 1918.4 MiB)
14:04:52.264 INFO  SparkContext - Created broadcast 1422 from broadcast at BamSink.java:76
14:04:52.265 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:04:52.265 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:04:52.265 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:04:52.276 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:04:52.277 INFO  DAGScheduler - Registering RDD 3638 (mapToPair at SparkUtils.java:161) as input to shuffle 101
14:04:52.277 INFO  DAGScheduler - Got job 435 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:04:52.277 INFO  DAGScheduler - Final stage: ResultStage 751 (runJob at SparkHadoopWriter.scala:83)
14:04:52.277 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 750)
14:04:52.277 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 750)
14:04:52.277 INFO  DAGScheduler - Submitting ShuffleMapStage 750 (MapPartitionsRDD[3638] at mapToPair at SparkUtils.java:161), which has no missing parents
14:04:52.278 INFO  MemoryStore - Block broadcast_1423 stored as values in memory (estimated size 18.1 KiB, free 1897.2 MiB)
14:04:52.279 INFO  MemoryStore - Block broadcast_1423_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1897.1 MiB)
14:04:52.279 INFO  BlockManagerInfo - Added broadcast_1423_piece0 in memory on localhost:46769 (size: 9.5 KiB, free: 1918.3 MiB)
14:04:52.279 INFO  SparkContext - Created broadcast 1423 from broadcast at DAGScheduler.scala:1580
14:04:52.279 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 750 (MapPartitionsRDD[3638] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:04:52.279 INFO  TaskSchedulerImpl - Adding task set 750.0 with 1 tasks resource profile 0
14:04:52.280 INFO  TaskSetManager - Starting task 0.0 in stage 750.0 (TID 676) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:04:52.280 INFO  Executor - Running task 0.0 in stage 750.0 (TID 676)
14:04:52.282 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:04:52.283 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.285 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:04:52.285 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.287 INFO  Executor - Finished task 0.0 in stage 750.0 (TID 676). 1922 bytes result sent to driver
14:04:52.287 INFO  TaskSetManager - Finished task 0.0 in stage 750.0 (TID 676) in 7 ms on localhost (executor driver) (1/1)
14:04:52.287 INFO  TaskSchedulerImpl - Removed TaskSet 750.0, whose tasks have all completed, from pool 
14:04:52.287 INFO  DAGScheduler - ShuffleMapStage 750 (mapToPair at SparkUtils.java:161) finished in 0.009 s
14:04:52.288 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.288 INFO  DAGScheduler - running: HashSet()
14:04:52.288 INFO  DAGScheduler - waiting: HashSet(ResultStage 751)
14:04:52.288 INFO  DAGScheduler - failed: HashSet()
14:04:52.288 INFO  DAGScheduler - Submitting ResultStage 751 (MapPartitionsRDD[3643] at mapToPair at BamSink.java:91), which has no missing parents
14:04:52.294 INFO  MemoryStore - Block broadcast_1424 stored as values in memory (estimated size 163.3 KiB, free 1897.0 MiB)
14:04:52.295 INFO  MemoryStore - Block broadcast_1424_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1896.9 MiB)
14:04:52.296 INFO  BlockManagerInfo - Added broadcast_1424_piece0 in memory on localhost:46769 (size: 73.4 KiB, free: 1918.3 MiB)
14:04:52.296 INFO  SparkContext - Created broadcast 1424 from broadcast at DAGScheduler.scala:1580
14:04:52.296 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 751 (MapPartitionsRDD[3643] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
14:04:52.296 INFO  TaskSchedulerImpl - Adding task set 751.0 with 1 tasks resource profile 0
14:04:52.297 INFO  TaskSetManager - Starting task 0.0 in stage 751.0 (TID 677) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:04:52.297 INFO  Executor - Running task 0.0 in stage 751.0 (TID 677)
14:04:52.300 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:04:52.301 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.303 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:04:52.303 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:04:52.303 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:04:52.303 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:04:52.303 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:04:52.303 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:04:52.314 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271404528310849878724994546_3643_r_000000_0' to file:/tmp/local111892862105095196395/markdups10447443287958991502.bam.parts/_temporary/0/task_202505271404528310849878724994546_3643_r_000000
14:04:52.314 INFO  SparkHadoopMapRedUtil - attempt_202505271404528310849878724994546_3643_r_000000_0: Committed. Elapsed time: 0 ms.
14:04:52.315 INFO  Executor - Finished task 0.0 in stage 751.0 (TID 677). 1858 bytes result sent to driver
14:04:52.315 INFO  TaskSetManager - Finished task 0.0 in stage 751.0 (TID 677) in 19 ms on localhost (executor driver) (1/1)
14:04:52.315 INFO  TaskSchedulerImpl - Removed TaskSet 751.0, whose tasks have all completed, from pool 
14:04:52.315 INFO  DAGScheduler - ResultStage 751 (runJob at SparkHadoopWriter.scala:83) finished in 0.027 s
14:04:52.315 INFO  DAGScheduler - Job 435 is finished. Cancelling potential speculative or zombie tasks for this job
14:04:52.315 INFO  TaskSchedulerImpl - Killing all running tasks in stage 751: Stage finished
14:04:52.316 INFO  DAGScheduler - Job 435 finished: runJob at SparkHadoopWriter.scala:83, took 0.039095 s
14:04:52.316 INFO  SparkHadoopWriter - Start to commit write Job job_202505271404528310849878724994546_3643.
14:04:52.320 INFO  SparkHadoopWriter - Write Job job_202505271404528310849878724994546_3643 committed. Elapsed time: 3 ms.
14:04:52.327 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local111892862105095196395/markdups10447443287958991502.bam
14:04:52.329 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local111892862105095196395/markdups10447443287958991502.bam done
14:04:52.329 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local111892862105095196395/markdups10447443287958991502.bam.parts/ to /tmp/local111892862105095196395/markdups10447443287958991502.bam.sbi
14:04:52.332 INFO  IndexFileMerger - Done merging .sbi files
14:04:52.332 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local111892862105095196395/markdups10447443287958991502.bam.parts/ to /tmp/local111892862105095196395/markdups10447443287958991502.bam.bai
14:04:52.335 INFO  IndexFileMerger - Done merging .bai files
14:04:52.335 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:04:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
14:04:52.352 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:04:52.352 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5c95f6f-SNAPSHOT
14:04:52.352 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:04:52.352 INFO  MarkDuplicatesSpark - Executing as root@9cd1444b9593 on Linux v6.11.0-1014-azure amd64
14:04:52.352 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:04:52.352 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:04:52 PM GMT
14:04:52.352 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:04:52.352 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:04:52.352 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:04:52.353 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:04:52.353 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:04:52.353 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:04:52.353 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:04:52.353 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:04:52.353 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:04:52.353 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:04:52.353 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:04:52.353 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:04:52.353 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:04:52.353 INFO  MarkDuplicatesSpark - Initializing engine
14:04:52.353 INFO  MarkDuplicatesSpark - Done initializing engine
14:04:52.353 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:04:52.355 INFO  MemoryStore - Block broadcast_1425 stored as values in memory (estimated size 305.5 KiB, free 1896.6 MiB)
14:04:52.362 INFO  MemoryStore - Block broadcast_1425_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1896.6 MiB)
14:04:52.362 INFO  BlockManagerInfo - Added broadcast_1425_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.2 MiB)
14:04:52.362 INFO  SparkContext - Created broadcast 1425 from newAPIHadoopFile at PathSplitSource.java:96
14:04:52.383 INFO  MemoryStore - Block broadcast_1426 stored as values in memory (estimated size 305.5 KiB, free 1896.3 MiB)
14:04:52.389 INFO  MemoryStore - Block broadcast_1426_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1896.2 MiB)
14:04:52.389 INFO  BlockManagerInfo - Added broadcast_1426_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.1 MiB)
14:04:52.390 INFO  SparkContext - Created broadcast 1426 from newAPIHadoopFile at PathSplitSource.java:96
14:04:52.421 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:04:52.421 INFO  FileInputFormat - Total input files to process : 1
14:04:52.422 INFO  DAGScheduler - Registering RDD 3657 (mapToPair at SparkUtils.java:161) as input to shuffle 102
14:04:52.422 INFO  DAGScheduler - Got job 436 (collect at SparkUtils.java:205) with 1 output partitions
14:04:52.422 INFO  DAGScheduler - Final stage: ResultStage 753 (collect at SparkUtils.java:205)
14:04:52.422 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 752)
14:04:52.422 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 752)
14:04:52.422 INFO  DAGScheduler - Submitting ShuffleMapStage 752 (MapPartitionsRDD[3657] at mapToPair at SparkUtils.java:161), which has no missing parents
14:04:52.439 INFO  MemoryStore - Block broadcast_1427 stored as values in memory (estimated size 459.2 KiB, free 1895.7 MiB)
14:04:52.441 INFO  MemoryStore - Block broadcast_1427_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1895.5 MiB)
14:04:52.441 INFO  BlockManagerInfo - Added broadcast_1427_piece0 in memory on localhost:46769 (size: 201.4 KiB, free: 1917.9 MiB)
14:04:52.441 INFO  SparkContext - Created broadcast 1427 from broadcast at DAGScheduler.scala:1580
14:04:52.442 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 752 (MapPartitionsRDD[3657] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:04:52.442 INFO  TaskSchedulerImpl - Adding task set 752.0 with 1 tasks resource profile 0
14:04:52.442 INFO  TaskSetManager - Starting task 0.0 in stage 752.0 (TID 678) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9651 bytes) 
14:04:52.442 INFO  Executor - Running task 0.0 in stage 752.0 (TID 678)
14:04:52.470 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam:0+1856
14:04:52.475 INFO  Executor - Finished task 0.0 in stage 752.0 (TID 678). 1148 bytes result sent to driver
14:04:52.475 INFO  TaskSetManager - Finished task 0.0 in stage 752.0 (TID 678) in 33 ms on localhost (executor driver) (1/1)
14:04:52.475 INFO  TaskSchedulerImpl - Removed TaskSet 752.0, whose tasks have all completed, from pool 
14:04:52.475 INFO  DAGScheduler - ShuffleMapStage 752 (mapToPair at SparkUtils.java:161) finished in 0.053 s
14:04:52.475 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.475 INFO  DAGScheduler - running: HashSet()
14:04:52.475 INFO  DAGScheduler - waiting: HashSet(ResultStage 753)
14:04:52.475 INFO  DAGScheduler - failed: HashSet()
14:04:52.475 INFO  DAGScheduler - Submitting ResultStage 753 (MapPartitionsRDD[3660] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:04:52.476 INFO  MemoryStore - Block broadcast_1428 stored as values in memory (estimated size 7.4 KiB, free 1895.5 MiB)
14:04:52.477 INFO  MemoryStore - Block broadcast_1428_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1895.5 MiB)
14:04:52.477 INFO  BlockManagerInfo - Added broadcast_1428_piece0 in memory on localhost:46769 (size: 4.1 KiB, free: 1917.9 MiB)
14:04:52.477 INFO  SparkContext - Created broadcast 1428 from broadcast at DAGScheduler.scala:1580
14:04:52.477 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 753 (MapPartitionsRDD[3660] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:04:52.477 INFO  TaskSchedulerImpl - Adding task set 753.0 with 1 tasks resource profile 0
14:04:52.478 INFO  TaskSetManager - Starting task 0.0 in stage 753.0 (TID 679) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:04:52.478 INFO  Executor - Running task 0.0 in stage 753.0 (TID 679)
14:04:52.479 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:04:52.479 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.481 INFO  Executor - Finished task 0.0 in stage 753.0 (TID 679). 2495 bytes result sent to driver
14:04:52.481 INFO  TaskSetManager - Finished task 0.0 in stage 753.0 (TID 679) in 3 ms on localhost (executor driver) (1/1)
14:04:52.481 INFO  TaskSchedulerImpl - Removed TaskSet 753.0, whose tasks have all completed, from pool 
14:04:52.481 INFO  DAGScheduler - ResultStage 753 (collect at SparkUtils.java:205) finished in 0.005 s
14:04:52.482 INFO  DAGScheduler - Job 436 is finished. Cancelling potential speculative or zombie tasks for this job
14:04:52.482 INFO  TaskSchedulerImpl - Killing all running tasks in stage 753: Stage finished
14:04:52.482 INFO  DAGScheduler - Job 436 finished: collect at SparkUtils.java:205, took 0.060731 s
14:04:52.486 INFO  MemoryStore - Block broadcast_1429 stored as values in memory (estimated size 1632.0 B, free 1895.5 MiB)
14:04:52.486 INFO  MemoryStore - Block broadcast_1429_piece0 stored as bytes in memory (estimated size 145.0 B, free 1895.5 MiB)
14:04:52.486 INFO  BlockManagerInfo - Added broadcast_1429_piece0 in memory on localhost:46769 (size: 145.0 B, free: 1917.9 MiB)
14:04:52.487 INFO  SparkContext - Created broadcast 1429 from broadcast at MarkDuplicatesSparkUtils.java:126
14:04:52.487 INFO  MemoryStore - Block broadcast_1430 stored as values in memory (estimated size 304.0 B, free 1895.5 MiB)
14:04:52.487 INFO  MemoryStore - Block broadcast_1430_piece0 stored as bytes in memory (estimated size 37.0 B, free 1895.5 MiB)
14:04:52.487 INFO  BlockManagerInfo - Added broadcast_1430_piece0 in memory on localhost:46769 (size: 37.0 B, free: 1917.9 MiB)
14:04:52.487 INFO  SparkContext - Created broadcast 1430 from broadcast at MarkDuplicatesSparkUtils.java:127
14:04:52.499 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:04:52.500 INFO  DAGScheduler - Registering RDD 3669 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 105
14:04:52.500 INFO  DAGScheduler - Registering RDD 3673 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 104
14:04:52.500 INFO  DAGScheduler - Registering RDD 3677 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 103
14:04:52.500 INFO  DAGScheduler - Got job 437 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:04:52.500 INFO  DAGScheduler - Final stage: ResultStage 758 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:04:52.500 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 757)
14:04:52.501 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 757)
14:04:52.501 INFO  DAGScheduler - Submitting ShuffleMapStage 755 (MapPartitionsRDD[3669] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:04:52.502 INFO  MemoryStore - Block broadcast_1431 stored as values in memory (estimated size 24.2 KiB, free 1895.5 MiB)
14:04:52.502 INFO  MemoryStore - Block broadcast_1431_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1895.5 MiB)
14:04:52.502 INFO  BlockManagerInfo - Added broadcast_1431_piece0 in memory on localhost:46769 (size: 12.6 KiB, free: 1917.9 MiB)
14:04:52.503 INFO  SparkContext - Created broadcast 1431 from broadcast at DAGScheduler.scala:1580
14:04:52.503 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 755 (MapPartitionsRDD[3669] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:04:52.503 INFO  TaskSchedulerImpl - Adding task set 755.0 with 1 tasks resource profile 0
14:04:52.503 INFO  TaskSetManager - Starting task 0.0 in stage 755.0 (TID 680) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:04:52.504 INFO  Executor - Running task 0.0 in stage 755.0 (TID 680)
14:04:52.505 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:04:52.505 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.508 INFO  Executor - Finished task 0.0 in stage 755.0 (TID 680). 1922 bytes result sent to driver
14:04:52.508 INFO  TaskSetManager - Finished task 0.0 in stage 755.0 (TID 680) in 5 ms on localhost (executor driver) (1/1)
14:04:52.509 INFO  TaskSchedulerImpl - Removed TaskSet 755.0, whose tasks have all completed, from pool 
14:04:52.509 INFO  DAGScheduler - ShuffleMapStage 755 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
14:04:52.509 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.509 INFO  DAGScheduler - running: HashSet()
14:04:52.509 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 756, ShuffleMapStage 757, ResultStage 758)
14:04:52.509 INFO  DAGScheduler - failed: HashSet()
14:04:52.509 INFO  DAGScheduler - Submitting ShuffleMapStage 756 (MapPartitionsRDD[3673] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:04:52.510 INFO  MemoryStore - Block broadcast_1432 stored as values in memory (estimated size 28.3 KiB, free 1895.5 MiB)
14:04:52.510 INFO  MemoryStore - Block broadcast_1432_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1895.5 MiB)
14:04:52.510 INFO  BlockManagerInfo - Added broadcast_1432_piece0 in memory on localhost:46769 (size: 14.8 KiB, free: 1917.9 MiB)
14:04:52.511 INFO  SparkContext - Created broadcast 1432 from broadcast at DAGScheduler.scala:1580
14:04:52.511 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 756 (MapPartitionsRDD[3673] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:04:52.511 INFO  TaskSchedulerImpl - Adding task set 756.0 with 1 tasks resource profile 0
14:04:52.511 INFO  TaskSetManager - Starting task 0.0 in stage 756.0 (TID 681) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:04:52.511 INFO  Executor - Running task 0.0 in stage 756.0 (TID 681)
14:04:52.513 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:04:52.513 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.516 INFO  Executor - Finished task 0.0 in stage 756.0 (TID 681). 1922 bytes result sent to driver
14:04:52.517 INFO  TaskSetManager - Finished task 0.0 in stage 756.0 (TID 681) in 5 ms on localhost (executor driver) (1/1)
14:04:52.517 INFO  TaskSchedulerImpl - Removed TaskSet 756.0, whose tasks have all completed, from pool 
14:04:52.517 INFO  DAGScheduler - ShuffleMapStage 756 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.008 s
14:04:52.517 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.517 INFO  DAGScheduler - running: HashSet()
14:04:52.517 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 757, ResultStage 758)
14:04:52.517 INFO  DAGScheduler - failed: HashSet()
14:04:52.517 INFO  DAGScheduler - Submitting ShuffleMapStage 757 (MapPartitionsRDD[3677] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:04:52.518 INFO  MemoryStore - Block broadcast_1433 stored as values in memory (estimated size 19.0 KiB, free 1895.4 MiB)
14:04:52.518 INFO  MemoryStore - Block broadcast_1433_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1895.4 MiB)
14:04:52.518 INFO  BlockManagerInfo - Added broadcast_1433_piece0 in memory on localhost:46769 (size: 9.7 KiB, free: 1917.9 MiB)
14:04:52.518 INFO  SparkContext - Created broadcast 1433 from broadcast at DAGScheduler.scala:1580
14:04:52.519 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 757 (MapPartitionsRDD[3677] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:04:52.519 INFO  TaskSchedulerImpl - Adding task set 757.0 with 1 tasks resource profile 0
14:04:52.519 INFO  TaskSetManager - Starting task 0.0 in stage 757.0 (TID 682) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:04:52.519 INFO  Executor - Running task 0.0 in stage 757.0 (TID 682)
14:04:52.521 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:04:52.521 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.523 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:04:52.523 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.525 INFO  Executor - Finished task 0.0 in stage 757.0 (TID 682). 1922 bytes result sent to driver
14:04:52.525 INFO  TaskSetManager - Finished task 0.0 in stage 757.0 (TID 682) in 6 ms on localhost (executor driver) (1/1)
14:04:52.525 INFO  TaskSchedulerImpl - Removed TaskSet 757.0, whose tasks have all completed, from pool 
14:04:52.525 INFO  DAGScheduler - ShuffleMapStage 757 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
14:04:52.525 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.525 INFO  DAGScheduler - running: HashSet()
14:04:52.525 INFO  DAGScheduler - waiting: HashSet(ResultStage 758)
14:04:52.525 INFO  DAGScheduler - failed: HashSet()
14:04:52.526 INFO  DAGScheduler - Submitting ResultStage 758 (MapPartitionsRDD[3679] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:04:52.526 INFO  MemoryStore - Block broadcast_1434 stored as values in memory (estimated size 20.2 KiB, free 1895.4 MiB)
14:04:52.527 INFO  MemoryStore - Block broadcast_1434_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1895.4 MiB)
14:04:52.527 INFO  BlockManagerInfo - Added broadcast_1434_piece0 in memory on localhost:46769 (size: 10.6 KiB, free: 1917.9 MiB)
14:04:52.527 INFO  SparkContext - Created broadcast 1434 from broadcast at DAGScheduler.scala:1580
14:04:52.527 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 758 (MapPartitionsRDD[3679] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:04:52.527 INFO  TaskSchedulerImpl - Adding task set 758.0 with 1 tasks resource profile 0
14:04:52.528 INFO  TaskSetManager - Starting task 0.0 in stage 758.0 (TID 683) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:04:52.528 INFO  Executor - Running task 0.0 in stage 758.0 (TID 683)
14:04:52.529 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:04:52.529 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.531 INFO  Executor - Finished task 0.0 in stage 758.0 (TID 683). 2010 bytes result sent to driver
14:04:52.531 INFO  TaskSetManager - Finished task 0.0 in stage 758.0 (TID 683) in 3 ms on localhost (executor driver) (1/1)
14:04:52.531 INFO  TaskSchedulerImpl - Removed TaskSet 758.0, whose tasks have all completed, from pool 
14:04:52.531 INFO  DAGScheduler - ResultStage 758 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
14:04:52.532 INFO  DAGScheduler - Job 437 is finished. Cancelling potential speculative or zombie tasks for this job
14:04:52.532 INFO  TaskSchedulerImpl - Killing all running tasks in stage 758: Stage finished
14:04:52.532 INFO  DAGScheduler - Job 437 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.032537 s
14:04:52.541 INFO  MemoryStore - Block broadcast_1435 stored as values in memory (estimated size 20.3 KiB, free 1895.4 MiB)
14:04:52.542 INFO  MemoryStore - Block broadcast_1435_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1895.4 MiB)
14:04:52.542 INFO  BlockManagerInfo - Added broadcast_1435_piece0 in memory on localhost:46769 (size: 1850.0 B, free: 1917.9 MiB)
14:04:52.542 INFO  SparkContext - Created broadcast 1435 from broadcast at ReadsSparkSink.java:133
14:04:52.543 INFO  MemoryStore - Block broadcast_1436 stored as values in memory (estimated size 20.4 KiB, free 1895.4 MiB)
14:04:52.543 INFO  MemoryStore - Block broadcast_1436_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1895.4 MiB)
14:04:52.543 INFO  BlockManagerInfo - Added broadcast_1436_piece0 in memory on localhost:46769 (size: 1850.0 B, free: 1917.9 MiB)
14:04:52.543 INFO  SparkContext - Created broadcast 1436 from broadcast at BamSink.java:76
14:04:52.545 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:04:52.545 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:04:52.545 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:04:52.556 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:04:52.557 INFO  DAGScheduler - Registering RDD 3681 (mapToPair at SparkUtils.java:161) as input to shuffle 106
14:04:52.557 INFO  DAGScheduler - Got job 438 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:04:52.557 INFO  DAGScheduler - Final stage: ResultStage 763 (runJob at SparkHadoopWriter.scala:83)
14:04:52.557 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 762)
14:04:52.557 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 762)
14:04:52.558 INFO  DAGScheduler - Submitting ShuffleMapStage 762 (MapPartitionsRDD[3681] at mapToPair at SparkUtils.java:161), which has no missing parents
14:04:52.559 INFO  MemoryStore - Block broadcast_1437 stored as values in memory (estimated size 18.1 KiB, free 1895.3 MiB)
14:04:52.559 INFO  MemoryStore - Block broadcast_1437_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1895.3 MiB)
14:04:52.559 INFO  BlockManagerInfo - Added broadcast_1437_piece0 in memory on localhost:46769 (size: 9.5 KiB, free: 1917.9 MiB)
14:04:52.559 INFO  SparkContext - Created broadcast 1437 from broadcast at DAGScheduler.scala:1580
14:04:52.560 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 762 (MapPartitionsRDD[3681] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:04:52.560 INFO  TaskSchedulerImpl - Adding task set 762.0 with 1 tasks resource profile 0
14:04:52.560 INFO  TaskSetManager - Starting task 0.0 in stage 762.0 (TID 684) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:04:52.560 INFO  Executor - Running task 0.0 in stage 762.0 (TID 684)
14:04:52.562 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:04:52.562 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.564 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:04:52.564 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.565 INFO  Executor - Finished task 0.0 in stage 762.0 (TID 684). 1922 bytes result sent to driver
14:04:52.566 INFO  TaskSetManager - Finished task 0.0 in stage 762.0 (TID 684) in 6 ms on localhost (executor driver) (1/1)
14:04:52.566 INFO  TaskSchedulerImpl - Removed TaskSet 762.0, whose tasks have all completed, from pool 
14:04:52.566 INFO  DAGScheduler - ShuffleMapStage 762 (mapToPair at SparkUtils.java:161) finished in 0.008 s
14:04:52.566 INFO  DAGScheduler - looking for newly runnable stages
14:04:52.566 INFO  DAGScheduler - running: HashSet()
14:04:52.566 INFO  DAGScheduler - waiting: HashSet(ResultStage 763)
14:04:52.566 INFO  DAGScheduler - failed: HashSet()
14:04:52.566 INFO  DAGScheduler - Submitting ResultStage 763 (MapPartitionsRDD[3686] at mapToPair at BamSink.java:91), which has no missing parents
14:04:52.573 INFO  MemoryStore - Block broadcast_1438 stored as values in memory (estimated size 163.3 KiB, free 1895.2 MiB)
14:04:52.574 INFO  MemoryStore - Block broadcast_1438_piece0 stored as bytes in memory (estimated size 73.5 KiB, free 1895.1 MiB)
14:04:52.574 INFO  BlockManagerInfo - Added broadcast_1438_piece0 in memory on localhost:46769 (size: 73.5 KiB, free: 1917.8 MiB)
14:04:52.574 INFO  SparkContext - Created broadcast 1438 from broadcast at DAGScheduler.scala:1580
14:04:52.574 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 763 (MapPartitionsRDD[3686] at mapToPair at BamSink.java:91) (first 15 tasks are for partitions Vector(0))
14:04:52.574 INFO  TaskSchedulerImpl - Adding task set 763.0 with 1 tasks resource profile 0
14:04:52.575 INFO  TaskSetManager - Starting task 0.0 in stage 763.0 (TID 685) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:04:52.575 INFO  Executor - Running task 0.0 in stage 763.0 (TID 685)
14:04:52.579 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:04:52.579 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:04:52.581 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:04:52.581 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:04:52.581 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:04:52.582 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
14:04:52.582 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:04:52.582 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:04:52.593 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271404524316649395818900380_3686_r_000000_0' to file:/tmp/local111892862105095196395/markdups15456076630922190447.bam.parts/_temporary/0/task_202505271404524316649395818900380_3686_r_000000
14:04:52.593 INFO  SparkHadoopMapRedUtil - attempt_202505271404524316649395818900380_3686_r_000000_0: Committed. Elapsed time: 0 ms.
14:04:52.593 INFO  Executor - Finished task 0.0 in stage 763.0 (TID 685). 1858 bytes result sent to driver
14:04:52.594 INFO  TaskSetManager - Finished task 0.0 in stage 763.0 (TID 685) in 19 ms on localhost (executor driver) (1/1)
14:04:52.594 INFO  TaskSchedulerImpl - Removed TaskSet 763.0, whose tasks have all completed, from pool 
14:04:52.594 INFO  DAGScheduler - ResultStage 763 (runJob at SparkHadoopWriter.scala:83) finished in 0.027 s
14:04:52.594 INFO  DAGScheduler - Job 438 is finished. Cancelling potential speculative or zombie tasks for this job
14:04:52.594 INFO  TaskSchedulerImpl - Killing all running tasks in stage 763: Stage finished
14:04:52.594 INFO  DAGScheduler - Job 438 finished: runJob at SparkHadoopWriter.scala:83, took 0.037554 s
14:04:52.594 INFO  SparkHadoopWriter - Start to commit write Job job_202505271404524316649395818900380_3686.
14:04:52.597 INFO  SparkHadoopWriter - Write Job job_202505271404524316649395818900380_3686 committed. Elapsed time: 2 ms.
14:04:52.603 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local111892862105095196395/markdups15456076630922190447.bam
14:04:52.605 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local111892862105095196395/markdups15456076630922190447.bam done
14:04:52.605 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local111892862105095196395/markdups15456076630922190447.bam.parts/ to /tmp/local111892862105095196395/markdups15456076630922190447.bam.sbi
14:04:52.608 INFO  IndexFileMerger - Done merging .sbi files
14:04:52.608 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local111892862105095196395/markdups15456076630922190447.bam.parts/ to /tmp/local111892862105095196395/markdups15456076630922190447.bam.bai
14:04:52.611 INFO  IndexFileMerger - Done merging .bai files
14:04:52.612 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:04:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:53 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:53 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:58 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:04:59 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:00 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:01 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:03 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:04 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:05 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
14:05:17.475 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:17.475 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5c95f6f-SNAPSHOT
14:05:17.475 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:05:17.475 INFO  MarkDuplicatesSpark - Executing as root@9cd1444b9593 on Linux v6.11.0-1014-azure amd64
14:05:17.475 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:05:17.475 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:05:17 PM GMT
14:05:17.475 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:17.475 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:17.476 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:05:17.476 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:05:17.476 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:05:17.476 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:05:17.476 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:05:17.476 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:05:17.476 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:05:17.476 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:05:17.476 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:05:17.476 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:05:17.476 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:05:17.476 INFO  MarkDuplicatesSpark - Initializing engine
14:05:17.476 INFO  MarkDuplicatesSpark - Done initializing engine
14:05:17.476 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:05:17.478 INFO  MemoryStore - Block broadcast_2015 stored as values in memory (estimated size 305.5 KiB, free 1911.7 MiB)
14:05:17.485 INFO  MemoryStore - Block broadcast_2015_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1911.6 MiB)
14:05:17.485 INFO  BlockManagerInfo - Added broadcast_2015_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.9 MiB)
14:05:17.485 INFO  SparkContext - Created broadcast 2015 from newAPIHadoopFile at PathSplitSource.java:96
14:05:17.506 INFO  MemoryStore - Block broadcast_2016 stored as values in memory (estimated size 305.5 KiB, free 1911.3 MiB)
14:05:17.512 INFO  MemoryStore - Block broadcast_2016_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1911.3 MiB)
14:05:17.513 INFO  BlockManagerInfo - Added broadcast_2016_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.9 MiB)
14:05:17.513 INFO  SparkContext - Created broadcast 2016 from newAPIHadoopFile at PathSplitSource.java:96
14:05:17.548 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:05:17.549 INFO  FileInputFormat - Total input files to process : 1
14:05:17.549 INFO  DAGScheduler - Registering RDD 5578 (mapToPair at SparkUtils.java:161) as input to shuffle 297
14:05:17.549 INFO  DAGScheduler - Got job 569 (collect at SparkUtils.java:205) with 1 output partitions
14:05:17.549 INFO  DAGScheduler - Final stage: ResultStage 1225 (collect at SparkUtils.java:205)
14:05:17.549 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1224)
14:05:17.550 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1224)
14:05:17.550 INFO  DAGScheduler - Submitting ShuffleMapStage 1224 (MapPartitionsRDD[5578] at mapToPair at SparkUtils.java:161), which has no missing parents
14:05:17.567 INFO  MemoryStore - Block broadcast_2017 stored as values in memory (estimated size 492.6 KiB, free 1910.8 MiB)
14:05:17.569 INFO  MemoryStore - Block broadcast_2017_piece0 stored as bytes in memory (estimated size 208.9 KiB, free 1910.6 MiB)
14:05:17.570 INFO  BlockManagerInfo - Added broadcast_2017_piece0 in memory on localhost:46769 (size: 208.9 KiB, free: 1918.6 MiB)
14:05:17.570 INFO  SparkContext - Created broadcast 2017 from broadcast at DAGScheduler.scala:1580
14:05:17.570 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1224 (MapPartitionsRDD[5578] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:05:17.570 INFO  TaskSchedulerImpl - Adding task set 1224.0 with 1 tasks resource profile 0
14:05:17.570 INFO  TaskSetManager - Starting task 0.0 in stage 1224.0 (TID 1056) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9674 bytes) 
14:05:17.571 INFO  Executor - Running task 0.0 in stage 1224.0 (TID 1056)
14:05:17.598 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam:0+13412
14:05:17.604 INFO  Executor - Finished task 0.0 in stage 1224.0 (TID 1056). 1148 bytes result sent to driver
14:05:17.604 INFO  TaskSetManager - Finished task 0.0 in stage 1224.0 (TID 1056) in 34 ms on localhost (executor driver) (1/1)
14:05:17.604 INFO  TaskSchedulerImpl - Removed TaskSet 1224.0, whose tasks have all completed, from pool 
14:05:17.604 INFO  DAGScheduler - ShuffleMapStage 1224 (mapToPair at SparkUtils.java:161) finished in 0.054 s
14:05:17.604 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.604 INFO  DAGScheduler - running: HashSet()
14:05:17.604 INFO  DAGScheduler - waiting: HashSet(ResultStage 1225)
14:05:17.605 INFO  DAGScheduler - failed: HashSet()
14:05:17.605 INFO  DAGScheduler - Submitting ResultStage 1225 (MapPartitionsRDD[5581] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:05:17.605 INFO  MemoryStore - Block broadcast_2018 stored as values in memory (estimated size 7.4 KiB, free 1910.6 MiB)
14:05:17.606 INFO  MemoryStore - Block broadcast_2018_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1910.6 MiB)
14:05:17.606 INFO  BlockManagerInfo - Added broadcast_2018_piece0 in memory on localhost:46769 (size: 4.1 KiB, free: 1918.6 MiB)
14:05:17.606 INFO  SparkContext - Created broadcast 2018 from broadcast at DAGScheduler.scala:1580
14:05:17.606 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1225 (MapPartitionsRDD[5581] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:05:17.606 INFO  TaskSchedulerImpl - Adding task set 1225.0 with 1 tasks resource profile 0
14:05:17.606 INFO  TaskSetManager - Starting task 0.0 in stage 1225.0 (TID 1057) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:17.607 INFO  Executor - Running task 0.0 in stage 1225.0 (TID 1057)
14:05:17.608 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:05:17.608 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.611 INFO  Executor - Finished task 0.0 in stage 1225.0 (TID 1057). 2329 bytes result sent to driver
14:05:17.612 INFO  TaskSetManager - Finished task 0.0 in stage 1225.0 (TID 1057) in 6 ms on localhost (executor driver) (1/1)
14:05:17.612 INFO  TaskSchedulerImpl - Removed TaskSet 1225.0, whose tasks have all completed, from pool 
14:05:17.612 INFO  DAGScheduler - ResultStage 1225 (collect at SparkUtils.java:205) finished in 0.007 s
14:05:17.612 INFO  DAGScheduler - Job 569 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:17.612 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1225: Stage finished
14:05:17.612 INFO  DAGScheduler - Job 569 finished: collect at SparkUtils.java:205, took 0.063801 s
14:05:17.618 INFO  MemoryStore - Block broadcast_2019 stored as values in memory (estimated size 7.8 KiB, free 1910.6 MiB)
14:05:17.618 INFO  MemoryStore - Block broadcast_2019_piece0 stored as bytes in memory (estimated size 540.0 B, free 1910.6 MiB)
14:05:17.618 INFO  BlockManagerInfo - Added broadcast_2019_piece0 in memory on localhost:46769 (size: 540.0 B, free: 1918.6 MiB)
14:05:17.618 INFO  SparkContext - Created broadcast 2019 from broadcast at MarkDuplicatesSparkUtils.java:126
14:05:17.618 INFO  MemoryStore - Block broadcast_2020 stored as values in memory (estimated size 2.6 KiB, free 1910.6 MiB)
14:05:17.619 INFO  MemoryStore - Block broadcast_2020_piece0 stored as bytes in memory (estimated size 209.0 B, free 1910.6 MiB)
14:05:17.619 INFO  BlockManagerInfo - Added broadcast_2020_piece0 in memory on localhost:46769 (size: 209.0 B, free: 1918.6 MiB)
14:05:17.619 INFO  SparkContext - Created broadcast 2020 from broadcast at MarkDuplicatesSparkUtils.java:127
14:05:17.636 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:05:17.637 INFO  DAGScheduler - Registering RDD 5590 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 300
14:05:17.637 INFO  DAGScheduler - Registering RDD 5594 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 299
14:05:17.637 INFO  DAGScheduler - Registering RDD 5598 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 298
14:05:17.637 INFO  DAGScheduler - Got job 570 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:05:17.637 INFO  DAGScheduler - Final stage: ResultStage 1230 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:05:17.637 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1229)
14:05:17.637 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1229)
14:05:17.638 INFO  DAGScheduler - Submitting ShuffleMapStage 1227 (MapPartitionsRDD[5590] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:05:17.638 INFO  MemoryStore - Block broadcast_2021 stored as values in memory (estimated size 57.6 KiB, free 1910.5 MiB)
14:05:17.639 INFO  MemoryStore - Block broadcast_2021_piece0 stored as bytes in memory (estimated size 19.8 KiB, free 1910.5 MiB)
14:05:17.639 INFO  BlockManagerInfo - Added broadcast_2021_piece0 in memory on localhost:46769 (size: 19.8 KiB, free: 1918.6 MiB)
14:05:17.639 INFO  SparkContext - Created broadcast 2021 from broadcast at DAGScheduler.scala:1580
14:05:17.640 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1227 (MapPartitionsRDD[5590] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:05:17.640 INFO  TaskSchedulerImpl - Adding task set 1227.0 with 1 tasks resource profile 0
14:05:17.640 INFO  TaskSetManager - Starting task 0.0 in stage 1227.0 (TID 1058) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:05:17.640 INFO  Executor - Running task 0.0 in stage 1227.0 (TID 1058)
14:05:17.642 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:05:17.642 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.646 INFO  Executor - Finished task 0.0 in stage 1227.0 (TID 1058). 1922 bytes result sent to driver
14:05:17.646 INFO  TaskSetManager - Finished task 0.0 in stage 1227.0 (TID 1058) in 6 ms on localhost (executor driver) (1/1)
14:05:17.646 INFO  TaskSchedulerImpl - Removed TaskSet 1227.0, whose tasks have all completed, from pool 
14:05:17.646 INFO  DAGScheduler - ShuffleMapStage 1227 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
14:05:17.646 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.646 INFO  DAGScheduler - running: HashSet()
14:05:17.646 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1228, ShuffleMapStage 1229, ResultStage 1230)
14:05:17.646 INFO  DAGScheduler - failed: HashSet()
14:05:17.647 INFO  DAGScheduler - Submitting ShuffleMapStage 1228 (MapPartitionsRDD[5594] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:05:17.648 INFO  MemoryStore - Block broadcast_2022 stored as values in memory (estimated size 61.7 KiB, free 1910.4 MiB)
14:05:17.649 INFO  MemoryStore - Block broadcast_2022_piece0 stored as bytes in memory (estimated size 22.0 KiB, free 1910.4 MiB)
14:05:17.649 INFO  BlockManagerInfo - Added broadcast_2022_piece0 in memory on localhost:46769 (size: 22.0 KiB, free: 1918.6 MiB)
14:05:17.649 INFO  SparkContext - Created broadcast 2022 from broadcast at DAGScheduler.scala:1580
14:05:17.649 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1228 (MapPartitionsRDD[5594] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:05:17.649 INFO  TaskSchedulerImpl - Adding task set 1228.0 with 1 tasks resource profile 0
14:05:17.649 INFO  TaskSetManager - Starting task 0.0 in stage 1228.0 (TID 1059) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:05:17.650 INFO  Executor - Running task 0.0 in stage 1228.0 (TID 1059)
14:05:17.652 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:05:17.652 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.658 INFO  Executor - Finished task 0.0 in stage 1228.0 (TID 1059). 1922 bytes result sent to driver
14:05:17.658 INFO  TaskSetManager - Finished task 0.0 in stage 1228.0 (TID 1059) in 9 ms on localhost (executor driver) (1/1)
14:05:17.658 INFO  TaskSchedulerImpl - Removed TaskSet 1228.0, whose tasks have all completed, from pool 
14:05:17.658 INFO  DAGScheduler - ShuffleMapStage 1228 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.011 s
14:05:17.658 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.658 INFO  DAGScheduler - running: HashSet()
14:05:17.658 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1229, ResultStage 1230)
14:05:17.658 INFO  DAGScheduler - failed: HashSet()
14:05:17.658 INFO  DAGScheduler - Submitting ShuffleMapStage 1229 (MapPartitionsRDD[5598] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:05:17.660 INFO  MemoryStore - Block broadcast_2023 stored as values in memory (estimated size 52.4 KiB, free 1910.4 MiB)
14:05:17.660 INFO  MemoryStore - Block broadcast_2023_piece0 stored as bytes in memory (estimated size 17.3 KiB, free 1910.3 MiB)
14:05:17.660 INFO  BlockManagerInfo - Added broadcast_2023_piece0 in memory on localhost:46769 (size: 17.3 KiB, free: 1918.6 MiB)
14:05:17.661 INFO  SparkContext - Created broadcast 2023 from broadcast at DAGScheduler.scala:1580
14:05:17.661 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1229 (MapPartitionsRDD[5598] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:05:17.661 INFO  TaskSchedulerImpl - Adding task set 1229.0 with 1 tasks resource profile 0
14:05:17.661 INFO  TaskSetManager - Starting task 0.0 in stage 1229.0 (TID 1060) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:05:17.661 INFO  Executor - Running task 0.0 in stage 1229.0 (TID 1060)
14:05:17.663 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:05:17.663 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.665 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:05:17.665 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.667 INFO  Executor - Finished task 0.0 in stage 1229.0 (TID 1060). 1922 bytes result sent to driver
14:05:17.667 INFO  TaskSetManager - Finished task 0.0 in stage 1229.0 (TID 1060) in 6 ms on localhost (executor driver) (1/1)
14:05:17.667 INFO  TaskSchedulerImpl - Removed TaskSet 1229.0, whose tasks have all completed, from pool 
14:05:17.667 INFO  DAGScheduler - ShuffleMapStage 1229 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
14:05:17.667 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.668 INFO  DAGScheduler - running: HashSet()
14:05:17.668 INFO  DAGScheduler - waiting: HashSet(ResultStage 1230)
14:05:17.668 INFO  DAGScheduler - failed: HashSet()
14:05:17.668 INFO  DAGScheduler - Submitting ResultStage 1230 (MapPartitionsRDD[5600] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:05:17.669 INFO  MemoryStore - Block broadcast_2024 stored as values in memory (estimated size 53.6 KiB, free 1910.3 MiB)
14:05:17.669 INFO  MemoryStore - Block broadcast_2024_piece0 stored as bytes in memory (estimated size 18.0 KiB, free 1910.3 MiB)
14:05:17.669 INFO  BlockManagerInfo - Added broadcast_2024_piece0 in memory on localhost:46769 (size: 18.0 KiB, free: 1918.6 MiB)
14:05:17.670 INFO  SparkContext - Created broadcast 2024 from broadcast at DAGScheduler.scala:1580
14:05:17.670 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1230 (MapPartitionsRDD[5600] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:05:17.670 INFO  TaskSchedulerImpl - Adding task set 1230.0 with 1 tasks resource profile 0
14:05:17.670 INFO  TaskSetManager - Starting task 0.0 in stage 1230.0 (TID 1061) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:17.670 INFO  Executor - Running task 0.0 in stage 1230.0 (TID 1061)
14:05:17.672 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:05:17.672 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.674 INFO  Executor - Finished task 0.0 in stage 1230.0 (TID 1061). 2371 bytes result sent to driver
14:05:17.674 INFO  TaskSetManager - Finished task 0.0 in stage 1230.0 (TID 1061) in 4 ms on localhost (executor driver) (1/1)
14:05:17.675 INFO  TaskSchedulerImpl - Removed TaskSet 1230.0, whose tasks have all completed, from pool 
14:05:17.675 INFO  DAGScheduler - ResultStage 1230 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.007 s
14:05:17.675 INFO  DAGScheduler - Job 570 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:17.675 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1230: Stage finished
14:05:17.675 INFO  DAGScheduler - Job 570 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.038341 s
14:05:17.691 INFO  MemoryStore - Block broadcast_2025 stored as values in memory (estimated size 179.4 KiB, free 1910.1 MiB)
14:05:17.691 INFO  MemoryStore - Block broadcast_2025_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1910.1 MiB)
14:05:17.692 INFO  BlockManagerInfo - Added broadcast_2025_piece0 in memory on localhost:46769 (size: 7.9 KiB, free: 1918.6 MiB)
14:05:17.692 INFO  SparkContext - Created broadcast 2025 from broadcast at ReadsSparkSink.java:133
14:05:17.696 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:05:17.696 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:05:17.696 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:05:17.711 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:05:17.711 INFO  DAGScheduler - Registering RDD 5602 (mapToPair at SparkUtils.java:161) as input to shuffle 301
14:05:17.711 INFO  DAGScheduler - Got job 571 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:05:17.711 INFO  DAGScheduler - Final stage: ResultStage 1235 (runJob at SparkHadoopWriter.scala:83)
14:05:17.711 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1234)
14:05:17.711 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1234)
14:05:17.712 INFO  DAGScheduler - Submitting ShuffleMapStage 1234 (MapPartitionsRDD[5602] at mapToPair at SparkUtils.java:161), which has no missing parents
14:05:17.713 INFO  MemoryStore - Block broadcast_2026 stored as values in memory (estimated size 51.5 KiB, free 1910.0 MiB)
14:05:17.713 INFO  MemoryStore - Block broadcast_2026_piece0 stored as bytes in memory (estimated size 16.8 KiB, free 1910.0 MiB)
14:05:17.713 INFO  BlockManagerInfo - Added broadcast_2026_piece0 in memory on localhost:46769 (size: 16.8 KiB, free: 1918.5 MiB)
14:05:17.713 INFO  SparkContext - Created broadcast 2026 from broadcast at DAGScheduler.scala:1580
14:05:17.714 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1234 (MapPartitionsRDD[5602] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:05:17.714 INFO  TaskSchedulerImpl - Adding task set 1234.0 with 1 tasks resource profile 0
14:05:17.714 INFO  TaskSetManager - Starting task 0.0 in stage 1234.0 (TID 1062) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:05:17.714 INFO  Executor - Running task 0.0 in stage 1234.0 (TID 1062)
14:05:17.716 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:05:17.716 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.718 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:05:17.718 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.720 INFO  Executor - Finished task 0.0 in stage 1234.0 (TID 1062). 1922 bytes result sent to driver
14:05:17.720 INFO  TaskSetManager - Finished task 0.0 in stage 1234.0 (TID 1062) in 6 ms on localhost (executor driver) (1/1)
14:05:17.720 INFO  TaskSchedulerImpl - Removed TaskSet 1234.0, whose tasks have all completed, from pool 
14:05:17.721 INFO  DAGScheduler - ShuffleMapStage 1234 (mapToPair at SparkUtils.java:161) finished in 0.009 s
14:05:17.721 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.721 INFO  DAGScheduler - running: HashSet()
14:05:17.721 INFO  DAGScheduler - waiting: HashSet(ResultStage 1235)
14:05:17.721 INFO  DAGScheduler - failed: HashSet()
14:05:17.721 INFO  DAGScheduler - Submitting ResultStage 1235 (MapPartitionsRDD[5608] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:05:17.727 INFO  MemoryStore - Block broadcast_2027 stored as values in memory (estimated size 196.3 KiB, free 1909.8 MiB)
14:05:17.728 INFO  MemoryStore - Block broadcast_2027_piece0 stored as bytes in memory (estimated size 80.5 KiB, free 1909.8 MiB)
14:05:17.729 INFO  BlockManagerInfo - Added broadcast_2027_piece0 in memory on localhost:46769 (size: 80.5 KiB, free: 1918.5 MiB)
14:05:17.729 INFO  SparkContext - Created broadcast 2027 from broadcast at DAGScheduler.scala:1580
14:05:17.729 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1235 (MapPartitionsRDD[5608] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
14:05:17.729 INFO  TaskSchedulerImpl - Adding task set 1235.0 with 1 tasks resource profile 0
14:05:17.729 INFO  TaskSetManager - Starting task 0.0 in stage 1235.0 (TID 1063) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:17.729 INFO  Executor - Running task 0.0 in stage 1235.0 (TID 1063)
14:05:17.733 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:05:17.733 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.735 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:05:17.735 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:05:17.735 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:05:17.742 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271405173429531217121764007_5608_m_000000_0' to file:/tmp/MarkDups3549202760821397238/MarkDups.sam.parts/_temporary/0/task_202505271405173429531217121764007_5608_m_000000
14:05:17.742 INFO  SparkHadoopMapRedUtil - attempt_202505271405173429531217121764007_5608_m_000000_0: Committed. Elapsed time: 0 ms.
14:05:17.742 INFO  Executor - Finished task 0.0 in stage 1235.0 (TID 1063). 1858 bytes result sent to driver
14:05:17.742 INFO  TaskSetManager - Finished task 0.0 in stage 1235.0 (TID 1063) in 13 ms on localhost (executor driver) (1/1)
14:05:17.742 INFO  TaskSchedulerImpl - Removed TaskSet 1235.0, whose tasks have all completed, from pool 
14:05:17.742 INFO  DAGScheduler - ResultStage 1235 (runJob at SparkHadoopWriter.scala:83) finished in 0.021 s
14:05:17.743 INFO  DAGScheduler - Job 571 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:17.743 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1235: Stage finished
14:05:17.743 INFO  DAGScheduler - Job 571 finished: runJob at SparkHadoopWriter.scala:83, took 0.032051 s
14:05:17.743 INFO  SparkHadoopWriter - Start to commit write Job job_202505271405173429531217121764007_5608.
14:05:17.746 INFO  SparkHadoopWriter - Write Job job_202505271405173429531217121764007_5608 committed. Elapsed time: 2 ms.
14:05:17.751 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups3549202760821397238/MarkDups.sam
14:05:17.753 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups3549202760821397238/MarkDups.sam done
14:05:17.754 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:05:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
14:05:17.769 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:17.769 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5c95f6f-SNAPSHOT
14:05:17.769 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:05:17.769 INFO  MarkDuplicatesSpark - Executing as root@9cd1444b9593 on Linux v6.11.0-1014-azure amd64
14:05:17.769 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:05:17.769 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:05:17 PM GMT
14:05:17.769 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:17.769 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:17.769 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:05:17.769 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:05:17.769 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:05:17.769 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:05:17.769 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:05:17.769 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:05:17.769 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:05:17.769 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:05:17.770 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:05:17.770 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:05:17.770 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:05:17.770 INFO  MarkDuplicatesSpark - Initializing engine
14:05:17.770 INFO  MarkDuplicatesSpark - Done initializing engine
14:05:17.770 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:05:17.772 INFO  MemoryStore - Block broadcast_2028 stored as values in memory (estimated size 305.5 KiB, free 1909.5 MiB)
14:05:17.780 INFO  MemoryStore - Block broadcast_2028_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1909.4 MiB)
14:05:17.780 INFO  BlockManagerInfo - Added broadcast_2028_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.4 MiB)
14:05:17.781 INFO  SparkContext - Created broadcast 2028 from newAPIHadoopFile at PathSplitSource.java:96
14:05:17.801 INFO  MemoryStore - Block broadcast_2029 stored as values in memory (estimated size 305.5 KiB, free 1909.1 MiB)
14:05:17.807 INFO  MemoryStore - Block broadcast_2029_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1909.0 MiB)
14:05:17.807 INFO  BlockManagerInfo - Added broadcast_2029_piece0 in memory on localhost:46769 (size: 64.0 KiB, free: 1918.3 MiB)
14:05:17.807 INFO  SparkContext - Created broadcast 2029 from newAPIHadoopFile at PathSplitSource.java:96
14:05:17.819 INFO  BlockManagerInfo - Removed broadcast_2012_piece0 on localhost:46769 in memory (size: 663.0 B, free: 1918.3 MiB)
14:05:17.821 INFO  BlockManagerInfo - Removed broadcast_2002_piece0 on localhost:46769 in memory (size: 64.0 KiB, free: 1918.4 MiB)
14:05:17.821 INFO  BlockManagerInfo - Removed broadcast_2007_piece0 on localhost:46769 in memory (size: 31.0 B, free: 1918.4 MiB)
14:05:17.822 INFO  BlockManagerInfo - Removed broadcast_2019_piece0 on localhost:46769 in memory (size: 540.0 B, free: 1918.4 MiB)
14:05:17.823 INFO  BlockManagerInfo - Removed broadcast_2013_piece0 on localhost:46769 in memory (size: 8.0 KiB, free: 1918.4 MiB)
14:05:17.823 INFO  BlockManagerInfo - Removed broadcast_2008_piece0 on localhost:46769 in memory (size: 11.2 KiB, free: 1918.4 MiB)
14:05:17.824 INFO  BlockManagerInfo - Removed broadcast_2018_piece0 on localhost:46769 in memory (size: 4.1 KiB, free: 1918.4 MiB)
14:05:17.824 INFO  BlockManagerInfo - Removed broadcast_1990_piece0 on localhost:46769 in memory (size: 64.0 KiB, free: 1918.5 MiB)
14:05:17.824 INFO  BlockManagerInfo - Removed broadcast_2028_piece0 on localhost:46769 in memory (size: 64.0 KiB, free: 1918.6 MiB)
14:05:17.825 INFO  BlockManagerInfo - Removed broadcast_2004_piece0 on localhost:46769 in memory (size: 200.3 KiB, free: 1918.7 MiB)
14:05:17.825 INFO  BlockManagerInfo - Removed broadcast_2016_piece0 on localhost:46769 in memory (size: 64.0 KiB, free: 1918.8 MiB)
14:05:17.825 INFO  BlockManagerInfo - Removed broadcast_2022_piece0 on localhost:46769 in memory (size: 22.0 KiB, free: 1918.8 MiB)
14:05:17.826 INFO  BlockManagerInfo - Removed broadcast_2005_piece0 on localhost:46769 in memory (size: 4.1 KiB, free: 1918.8 MiB)
14:05:17.826 INFO  BlockManagerInfo - Removed broadcast_1994_piece0 on localhost:46769 in memory (size: 31.0 B, free: 1918.8 MiB)
14:05:17.826 INFO  BlockManagerInfo - Removed broadcast_2025_piece0 on localhost:46769 in memory (size: 7.9 KiB, free: 1918.8 MiB)
14:05:17.827 INFO  BlockManagerInfo - Removed broadcast_2026_piece0 on localhost:46769 in memory (size: 16.8 KiB, free: 1918.9 MiB)
14:05:17.827 INFO  BlockManagerInfo - Removed broadcast_2020_piece0 on localhost:46769 in memory (size: 209.0 B, free: 1918.9 MiB)
14:05:17.827 INFO  BlockManagerInfo - Removed broadcast_2009_piece0 on localhost:46769 in memory (size: 13.2 KiB, free: 1918.9 MiB)
14:05:17.828 INFO  BlockManagerInfo - Removed broadcast_2015_piece0 on localhost:46769 in memory (size: 64.0 KiB, free: 1918.9 MiB)
14:05:17.828 INFO  BlockManagerInfo - Removed broadcast_2017_piece0 on localhost:46769 in memory (size: 208.9 KiB, free: 1919.1 MiB)
14:05:17.828 INFO  BlockManagerInfo - Removed broadcast_2014_piece0 on localhost:46769 in memory (size: 71.6 KiB, free: 1919.2 MiB)
14:05:17.828 INFO  BlockManagerInfo - Removed broadcast_1993_piece0 on localhost:46769 in memory (size: 19.0 B, free: 1919.2 MiB)
14:05:17.829 INFO  BlockManagerInfo - Removed broadcast_2003_piece0 on localhost:46769 in memory (size: 64.0 KiB, free: 1919.3 MiB)
14:05:17.829 INFO  BlockManagerInfo - Removed broadcast_1999_piece0 on localhost:46769 in memory (size: 663.0 B, free: 1919.3 MiB)
14:05:17.830 INFO  BlockManagerInfo - Removed broadcast_2011_piece0 on localhost:46769 in memory (size: 9.1 KiB, free: 1919.3 MiB)
14:05:17.830 INFO  BlockManagerInfo - Removed broadcast_2024_piece0 on localhost:46769 in memory (size: 18.0 KiB, free: 1919.3 MiB)
14:05:17.830 INFO  BlockManagerInfo - Removed broadcast_2006_piece0 on localhost:46769 in memory (size: 19.0 B, free: 1919.3 MiB)
14:05:17.831 INFO  BlockManagerInfo - Removed broadcast_2001_piece0 on localhost:46769 in memory (size: 71.6 KiB, free: 1919.4 MiB)
14:05:17.831 INFO  BlockManagerInfo - Removed broadcast_2023_piece0 on localhost:46769 in memory (size: 17.3 KiB, free: 1919.4 MiB)
14:05:17.831 INFO  BlockManagerInfo - Removed broadcast_2021_piece0 on localhost:46769 in memory (size: 19.8 KiB, free: 1919.4 MiB)
14:05:17.832 INFO  BlockManagerInfo - Removed broadcast_2010_piece0 on localhost:46769 in memory (size: 8.5 KiB, free: 1919.4 MiB)
14:05:17.832 INFO  BlockManagerInfo - Removed broadcast_2027_piece0 on localhost:46769 in memory (size: 80.5 KiB, free: 1919.5 MiB)
14:05:17.848 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:05:17.848 INFO  FileInputFormat - Total input files to process : 1
14:05:17.848 INFO  DAGScheduler - Registering RDD 5622 (mapToPair at SparkUtils.java:161) as input to shuffle 302
14:05:17.848 INFO  DAGScheduler - Got job 572 (collect at SparkUtils.java:205) with 1 output partitions
14:05:17.849 INFO  DAGScheduler - Final stage: ResultStage 1237 (collect at SparkUtils.java:205)
14:05:17.849 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1236)
14:05:17.849 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1236)
14:05:17.849 INFO  DAGScheduler - Submitting ShuffleMapStage 1236 (MapPartitionsRDD[5622] at mapToPair at SparkUtils.java:161), which has no missing parents
14:05:17.865 INFO  MemoryStore - Block broadcast_2030 stored as values in memory (estimated size 456.1 KiB, free 1913.6 MiB)
14:05:17.868 INFO  MemoryStore - Block broadcast_2030_piece0 stored as bytes in memory (estimated size 200.0 KiB, free 1913.4 MiB)
14:05:17.868 INFO  BlockManagerInfo - Added broadcast_2030_piece0 in memory on localhost:46769 (size: 200.0 KiB, free: 1919.3 MiB)
14:05:17.868 INFO  SparkContext - Created broadcast 2030 from broadcast at DAGScheduler.scala:1580
14:05:17.868 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1236 (MapPartitionsRDD[5622] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:05:17.868 INFO  TaskSchedulerImpl - Adding task set 1236.0 with 1 tasks resource profile 0
14:05:17.869 INFO  TaskSetManager - Starting task 0.0 in stage 1236.0 (TID 1064) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9653 bytes) 
14:05:17.869 INFO  Executor - Running task 0.0 in stage 1236.0 (TID 1064)
14:05:17.898 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam:0+678
14:05:17.903 INFO  Executor - Finished task 0.0 in stage 1236.0 (TID 1064). 1148 bytes result sent to driver
14:05:17.903 INFO  TaskSetManager - Finished task 0.0 in stage 1236.0 (TID 1064) in 34 ms on localhost (executor driver) (1/1)
14:05:17.903 INFO  TaskSchedulerImpl - Removed TaskSet 1236.0, whose tasks have all completed, from pool 
14:05:17.903 INFO  DAGScheduler - ShuffleMapStage 1236 (mapToPair at SparkUtils.java:161) finished in 0.054 s
14:05:17.903 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.903 INFO  DAGScheduler - running: HashSet()
14:05:17.903 INFO  DAGScheduler - waiting: HashSet(ResultStage 1237)
14:05:17.903 INFO  DAGScheduler - failed: HashSet()
14:05:17.904 INFO  DAGScheduler - Submitting ResultStage 1237 (MapPartitionsRDD[5625] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:05:17.904 INFO  MemoryStore - Block broadcast_2031 stored as values in memory (estimated size 7.4 KiB, free 1913.3 MiB)
14:05:17.904 INFO  MemoryStore - Block broadcast_2031_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1913.3 MiB)
14:05:17.905 INFO  BlockManagerInfo - Added broadcast_2031_piece0 in memory on localhost:46769 (size: 4.1 KiB, free: 1919.3 MiB)
14:05:17.905 INFO  SparkContext - Created broadcast 2031 from broadcast at DAGScheduler.scala:1580
14:05:17.905 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1237 (MapPartitionsRDD[5625] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:05:17.905 INFO  TaskSchedulerImpl - Adding task set 1237.0 with 1 tasks resource profile 0
14:05:17.905 INFO  TaskSetManager - Starting task 0.0 in stage 1237.0 (TID 1065) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:17.906 INFO  Executor - Running task 0.0 in stage 1237.0 (TID 1065)
14:05:17.906 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:05:17.906 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.908 INFO  Executor - Finished task 0.0 in stage 1237.0 (TID 1065). 2269 bytes result sent to driver
14:05:17.908 INFO  TaskSetManager - Finished task 0.0 in stage 1237.0 (TID 1065) in 3 ms on localhost (executor driver) (1/1)
14:05:17.908 INFO  TaskSchedulerImpl - Removed TaskSet 1237.0, whose tasks have all completed, from pool 
14:05:17.908 INFO  DAGScheduler - ResultStage 1237 (collect at SparkUtils.java:205) finished in 0.004 s
14:05:17.908 INFO  DAGScheduler - Job 572 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:17.908 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1237: Stage finished
14:05:17.908 INFO  DAGScheduler - Job 572 finished: collect at SparkUtils.java:205, took 0.060475 s
14:05:17.912 INFO  MemoryStore - Block broadcast_2032 stored as values in memory (estimated size 136.0 B, free 1913.3 MiB)
14:05:17.912 INFO  MemoryStore - Block broadcast_2032_piece0 stored as bytes in memory (estimated size 24.0 B, free 1913.3 MiB)
14:05:17.912 INFO  BlockManagerInfo - Added broadcast_2032_piece0 in memory on localhost:46769 (size: 24.0 B, free: 1919.3 MiB)
14:05:17.913 INFO  SparkContext - Created broadcast 2032 from broadcast at MarkDuplicatesSparkUtils.java:126
14:05:17.913 INFO  MemoryStore - Block broadcast_2033 stored as values in memory (estimated size 136.0 B, free 1913.3 MiB)
14:05:17.913 INFO  MemoryStore - Block broadcast_2033_piece0 stored as bytes in memory (estimated size 21.0 B, free 1913.3 MiB)
14:05:17.913 INFO  BlockManagerInfo - Added broadcast_2033_piece0 in memory on localhost:46769 (size: 21.0 B, free: 1919.3 MiB)
14:05:17.913 INFO  SparkContext - Created broadcast 2033 from broadcast at MarkDuplicatesSparkUtils.java:127
14:05:17.925 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:05:17.925 INFO  DAGScheduler - Registering RDD 5634 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 305
14:05:17.925 INFO  DAGScheduler - Registering RDD 5638 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 304
14:05:17.925 INFO  DAGScheduler - Registering RDD 5642 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 303
14:05:17.925 INFO  DAGScheduler - Got job 573 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:05:17.925 INFO  DAGScheduler - Final stage: ResultStage 1242 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:05:17.925 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1241)
14:05:17.925 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1241)
14:05:17.926 INFO  DAGScheduler - Submitting ShuffleMapStage 1239 (MapPartitionsRDD[5634] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:05:17.926 INFO  MemoryStore - Block broadcast_2034 stored as values in memory (estimated size 21.1 KiB, free 1913.3 MiB)
14:05:17.927 INFO  MemoryStore - Block broadcast_2034_piece0 stored as bytes in memory (estimated size 10.9 KiB, free 1913.3 MiB)
14:05:17.927 INFO  BlockManagerInfo - Added broadcast_2034_piece0 in memory on localhost:46769 (size: 10.9 KiB, free: 1919.3 MiB)
14:05:17.927 INFO  SparkContext - Created broadcast 2034 from broadcast at DAGScheduler.scala:1580
14:05:17.927 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1239 (MapPartitionsRDD[5634] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:05:17.927 INFO  TaskSchedulerImpl - Adding task set 1239.0 with 1 tasks resource profile 0
14:05:17.927 INFO  TaskSetManager - Starting task 0.0 in stage 1239.0 (TID 1066) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:05:17.928 INFO  Executor - Running task 0.0 in stage 1239.0 (TID 1066)
14:05:17.929 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:05:17.929 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.932 INFO  Executor - Finished task 0.0 in stage 1239.0 (TID 1066). 1879 bytes result sent to driver
14:05:17.933 INFO  TaskSetManager - Finished task 0.0 in stage 1239.0 (TID 1066) in 6 ms on localhost (executor driver) (1/1)
14:05:17.933 INFO  TaskSchedulerImpl - Removed TaskSet 1239.0, whose tasks have all completed, from pool 
14:05:17.933 INFO  DAGScheduler - ShuffleMapStage 1239 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
14:05:17.933 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.933 INFO  DAGScheduler - running: HashSet()
14:05:17.933 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1240, ShuffleMapStage 1241, ResultStage 1242)
14:05:17.933 INFO  DAGScheduler - failed: HashSet()
14:05:17.933 INFO  DAGScheduler - Submitting ShuffleMapStage 1240 (MapPartitionsRDD[5638] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:05:17.934 INFO  MemoryStore - Block broadcast_2035 stored as values in memory (estimated size 25.2 KiB, free 1913.3 MiB)
14:05:17.934 INFO  MemoryStore - Block broadcast_2035_piece0 stored as bytes in memory (estimated size 13.1 KiB, free 1913.3 MiB)
14:05:17.934 INFO  BlockManagerInfo - Added broadcast_2035_piece0 in memory on localhost:46769 (size: 13.1 KiB, free: 1919.3 MiB)
14:05:17.934 INFO  SparkContext - Created broadcast 2035 from broadcast at DAGScheduler.scala:1580
14:05:17.935 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1240 (MapPartitionsRDD[5638] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:05:17.935 INFO  TaskSchedulerImpl - Adding task set 1240.0 with 1 tasks resource profile 0
14:05:17.935 INFO  TaskSetManager - Starting task 0.0 in stage 1240.0 (TID 1067) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:05:17.935 INFO  Executor - Running task 0.0 in stage 1240.0 (TID 1067)
14:05:17.936 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:05:17.936 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.939 INFO  Executor - Finished task 0.0 in stage 1240.0 (TID 1067). 1879 bytes result sent to driver
14:05:17.939 INFO  TaskSetManager - Finished task 0.0 in stage 1240.0 (TID 1067) in 4 ms on localhost (executor driver) (1/1)
14:05:17.939 INFO  TaskSchedulerImpl - Removed TaskSet 1240.0, whose tasks have all completed, from pool 
14:05:17.939 INFO  DAGScheduler - ShuffleMapStage 1240 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.006 s
14:05:17.939 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.939 INFO  DAGScheduler - running: HashSet()
14:05:17.939 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1241, ResultStage 1242)
14:05:17.939 INFO  DAGScheduler - failed: HashSet()
14:05:17.940 INFO  DAGScheduler - Submitting ShuffleMapStage 1241 (MapPartitionsRDD[5642] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:05:17.940 INFO  MemoryStore - Block broadcast_2036 stored as values in memory (estimated size 15.9 KiB, free 1913.3 MiB)
14:05:17.940 INFO  MemoryStore - Block broadcast_2036_piece0 stored as bytes in memory (estimated size 8.3 KiB, free 1913.3 MiB)
14:05:17.941 INFO  BlockManagerInfo - Added broadcast_2036_piece0 in memory on localhost:46769 (size: 8.3 KiB, free: 1919.3 MiB)
14:05:17.941 INFO  SparkContext - Created broadcast 2036 from broadcast at DAGScheduler.scala:1580
14:05:17.941 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1241 (MapPartitionsRDD[5642] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:05:17.941 INFO  TaskSchedulerImpl - Adding task set 1241.0 with 1 tasks resource profile 0
14:05:17.941 INFO  TaskSetManager - Starting task 0.0 in stage 1241.0 (TID 1068) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:05:17.941 INFO  Executor - Running task 0.0 in stage 1241.0 (TID 1068)
14:05:17.942 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:05:17.942 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.943 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:05:17.943 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.944 INFO  Executor - Finished task 0.0 in stage 1241.0 (TID 1068). 1879 bytes result sent to driver
14:05:17.944 INFO  TaskSetManager - Finished task 0.0 in stage 1241.0 (TID 1068) in 3 ms on localhost (executor driver) (1/1)
14:05:17.944 INFO  TaskSchedulerImpl - Removed TaskSet 1241.0, whose tasks have all completed, from pool 
14:05:17.944 INFO  DAGScheduler - ShuffleMapStage 1241 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.004 s
14:05:17.944 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.944 INFO  DAGScheduler - running: HashSet()
14:05:17.944 INFO  DAGScheduler - waiting: HashSet(ResultStage 1242)
14:05:17.944 INFO  DAGScheduler - failed: HashSet()
14:05:17.945 INFO  DAGScheduler - Submitting ResultStage 1242 (MapPartitionsRDD[5644] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:05:17.945 INFO  MemoryStore - Block broadcast_2037 stored as values in memory (estimated size 17.1 KiB, free 1913.2 MiB)
14:05:17.945 INFO  MemoryStore - Block broadcast_2037_piece0 stored as bytes in memory (estimated size 9.0 KiB, free 1913.2 MiB)
14:05:17.945 INFO  BlockManagerInfo - Added broadcast_2037_piece0 in memory on localhost:46769 (size: 9.0 KiB, free: 1919.3 MiB)
14:05:17.946 INFO  SparkContext - Created broadcast 2037 from broadcast at DAGScheduler.scala:1580
14:05:17.946 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1242 (MapPartitionsRDD[5644] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:05:17.946 INFO  TaskSchedulerImpl - Adding task set 1242.0 with 1 tasks resource profile 0
14:05:17.946 INFO  TaskSetManager - Starting task 0.0 in stage 1242.0 (TID 1069) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:17.946 INFO  Executor - Running task 0.0 in stage 1242.0 (TID 1069)
14:05:17.947 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:05:17.947 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.948 INFO  Executor - Finished task 0.0 in stage 1242.0 (TID 1069). 1887 bytes result sent to driver
14:05:17.948 INFO  TaskSetManager - Finished task 0.0 in stage 1242.0 (TID 1069) in 2 ms on localhost (executor driver) (1/1)
14:05:17.948 INFO  TaskSchedulerImpl - Removed TaskSet 1242.0, whose tasks have all completed, from pool 
14:05:17.948 INFO  DAGScheduler - ResultStage 1242 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.003 s
14:05:17.948 INFO  DAGScheduler - Job 573 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:17.948 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1242: Stage finished
14:05:17.949 INFO  DAGScheduler - Job 573 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.023859 s
14:05:17.958 INFO  MemoryStore - Block broadcast_2038 stored as values in memory (estimated size 5.6 KiB, free 1913.2 MiB)
14:05:17.958 INFO  MemoryStore - Block broadcast_2038_piece0 stored as bytes in memory (estimated size 500.0 B, free 1913.2 MiB)
14:05:17.958 INFO  BlockManagerInfo - Added broadcast_2038_piece0 in memory on localhost:46769 (size: 500.0 B, free: 1919.3 MiB)
14:05:17.958 INFO  SparkContext - Created broadcast 2038 from broadcast at ReadsSparkSink.java:133
14:05:17.961 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:05:17.961 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:05:17.961 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:05:17.972 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:05:17.973 INFO  DAGScheduler - Registering RDD 5646 (mapToPair at SparkUtils.java:161) as input to shuffle 306
14:05:17.973 INFO  DAGScheduler - Got job 574 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:05:17.973 INFO  DAGScheduler - Final stage: ResultStage 1247 (runJob at SparkHadoopWriter.scala:83)
14:05:17.973 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1246)
14:05:17.973 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1246)
14:05:17.973 INFO  DAGScheduler - Submitting ShuffleMapStage 1246 (MapPartitionsRDD[5646] at mapToPair at SparkUtils.java:161), which has no missing parents
14:05:17.974 INFO  MemoryStore - Block broadcast_2039 stored as values in memory (estimated size 15.0 KiB, free 1913.2 MiB)
14:05:17.974 INFO  MemoryStore - Block broadcast_2039_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1913.2 MiB)
14:05:17.974 INFO  BlockManagerInfo - Added broadcast_2039_piece0 in memory on localhost:46769 (size: 7.9 KiB, free: 1919.2 MiB)
14:05:17.974 INFO  SparkContext - Created broadcast 2039 from broadcast at DAGScheduler.scala:1580
14:05:17.975 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1246 (MapPartitionsRDD[5646] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:05:17.975 INFO  TaskSchedulerImpl - Adding task set 1246.0 with 1 tasks resource profile 0
14:05:17.975 INFO  TaskSetManager - Starting task 0.0 in stage 1246.0 (TID 1070) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:05:17.975 INFO  Executor - Running task 0.0 in stage 1246.0 (TID 1070)
14:05:17.977 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:05:17.977 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.978 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:05:17.978 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.979 INFO  Executor - Finished task 0.0 in stage 1246.0 (TID 1070). 1922 bytes result sent to driver
14:05:17.980 INFO  TaskSetManager - Finished task 0.0 in stage 1246.0 (TID 1070) in 5 ms on localhost (executor driver) (1/1)
14:05:17.980 INFO  TaskSchedulerImpl - Removed TaskSet 1246.0, whose tasks have all completed, from pool 
14:05:17.980 INFO  DAGScheduler - ShuffleMapStage 1246 (mapToPair at SparkUtils.java:161) finished in 0.007 s
14:05:17.980 INFO  DAGScheduler - looking for newly runnable stages
14:05:17.980 INFO  DAGScheduler - running: HashSet()
14:05:17.980 INFO  DAGScheduler - waiting: HashSet(ResultStage 1247)
14:05:17.980 INFO  DAGScheduler - failed: HashSet()
14:05:17.980 INFO  DAGScheduler - Submitting ResultStage 1247 (MapPartitionsRDD[5652] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:05:17.986 INFO  MemoryStore - Block broadcast_2040 stored as values in memory (estimated size 159.8 KiB, free 1913.0 MiB)
14:05:17.987 INFO  MemoryStore - Block broadcast_2040_piece0 stored as bytes in memory (estimated size 71.5 KiB, free 1913.0 MiB)
14:05:17.987 INFO  BlockManagerInfo - Added broadcast_2040_piece0 in memory on localhost:46769 (size: 71.5 KiB, free: 1919.2 MiB)
14:05:17.987 INFO  SparkContext - Created broadcast 2040 from broadcast at DAGScheduler.scala:1580
14:05:17.987 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1247 (MapPartitionsRDD[5652] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
14:05:17.987 INFO  TaskSchedulerImpl - Adding task set 1247.0 with 1 tasks resource profile 0
14:05:17.988 INFO  TaskSetManager - Starting task 0.0 in stage 1247.0 (TID 1071) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:17.988 INFO  Executor - Running task 0.0 in stage 1247.0 (TID 1071)
14:05:17.991 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:05:17.991 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:17.992 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:05:17.992 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:05:17.992 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:05:17.998 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271405177681914020792431088_5652_m_000000_0' to file:/tmp/MarkDups15491179522124335576/MarkDups.sam.parts/_temporary/0/task_202505271405177681914020792431088_5652_m_000000
14:05:17.998 INFO  SparkHadoopMapRedUtil - attempt_202505271405177681914020792431088_5652_m_000000_0: Committed. Elapsed time: 0 ms.
14:05:17.998 INFO  Executor - Finished task 0.0 in stage 1247.0 (TID 1071). 1858 bytes result sent to driver
14:05:17.998 INFO  TaskSetManager - Finished task 0.0 in stage 1247.0 (TID 1071) in 11 ms on localhost (executor driver) (1/1)
14:05:17.999 INFO  TaskSchedulerImpl - Removed TaskSet 1247.0, whose tasks have all completed, from pool 
14:05:17.999 INFO  DAGScheduler - ResultStage 1247 (runJob at SparkHadoopWriter.scala:83) finished in 0.019 s
14:05:17.999 INFO  DAGScheduler - Job 574 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:17.999 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1247: Stage finished
14:05:17.999 INFO  DAGScheduler - Job 574 finished: runJob at SparkHadoopWriter.scala:83, took 0.026397 s
14:05:17.999 INFO  SparkHadoopWriter - Start to commit write Job job_202505271405177681914020792431088_5652.
14:05:18.001 INFO  SparkHadoopWriter - Write Job job_202505271405177681914020792431088_5652 committed. Elapsed time: 2 ms.
14:05:18.005 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups15491179522124335576/MarkDups.sam
14:05:18.007 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups15491179522124335576/MarkDups.sam done
14:05:18.007 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:05:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
14:05:18.023 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:18.023 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) v5c95f6f-SNAPSHOT
14:05:18.023 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
14:05:18.023 INFO  MarkDuplicatesSpark - Executing as root@9cd1444b9593 on Linux v6.11.0-1014-azure amd64
14:05:18.023 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
14:05:18.023 INFO  MarkDuplicatesSpark - Start Date/Time: May 27, 2025 at 2:05:18 PM GMT
14:05:18.023 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:18.023 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
14:05:18.023 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
14:05:18.023 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
14:05:18.023 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
14:05:18.023 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:05:18.023 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:05:18.023 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:05:18.023 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:05:18.023 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
14:05:18.023 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
14:05:18.023 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
14:05:18.023 INFO  MarkDuplicatesSpark - Requester pays: disabled
14:05:18.023 INFO  MarkDuplicatesSpark - Initializing engine
14:05:18.023 INFO  MarkDuplicatesSpark - Done initializing engine
14:05:18.023 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
14:05:18.025 INFO  MemoryStore - Block broadcast_2041 stored as values in memory (estimated size 305.5 KiB, free 1912.7 MiB)
14:05:18.032 INFO  MemoryStore - Block broadcast_2041_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1912.6 MiB)
14:05:18.032 INFO  BlockManagerInfo - Added broadcast_2041_piece0 in memory on localhost:46769 (size: 64.1 KiB, free: 1919.1 MiB)
14:05:18.032 INFO  SparkContext - Created broadcast 2041 from newAPIHadoopFile at PathSplitSource.java:96
14:05:18.052 INFO  MemoryStore - Block broadcast_2042 stored as values in memory (estimated size 305.5 KiB, free 1912.3 MiB)
14:05:18.058 INFO  MemoryStore - Block broadcast_2042_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1912.2 MiB)
14:05:18.058 INFO  BlockManagerInfo - Added broadcast_2042_piece0 in memory on localhost:46769 (size: 64.1 KiB, free: 1919.0 MiB)
14:05:18.058 INFO  SparkContext - Created broadcast 2042 from newAPIHadoopFile at PathSplitSource.java:96
14:05:18.090 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
14:05:18.091 INFO  FileInputFormat - Total input files to process : 1
14:05:18.091 INFO  DAGScheduler - Registering RDD 5666 (mapToPair at SparkUtils.java:161) as input to shuffle 307
14:05:18.091 INFO  DAGScheduler - Got job 575 (collect at SparkUtils.java:205) with 1 output partitions
14:05:18.091 INFO  DAGScheduler - Final stage: ResultStage 1249 (collect at SparkUtils.java:205)
14:05:18.091 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1248)
14:05:18.091 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1248)
14:05:18.091 INFO  DAGScheduler - Submitting ShuffleMapStage 1248 (MapPartitionsRDD[5666] at mapToPair at SparkUtils.java:161), which has no missing parents
14:05:18.108 INFO  MemoryStore - Block broadcast_2043 stored as values in memory (estimated size 480.2 KiB, free 1911.8 MiB)
14:05:18.111 INFO  MemoryStore - Block broadcast_2043_piece0 stored as bytes in memory (estimated size 206.2 KiB, free 1911.6 MiB)
14:05:18.111 INFO  BlockManagerInfo - Added broadcast_2043_piece0 in memory on localhost:46769 (size: 206.2 KiB, free: 1918.8 MiB)
14:05:18.111 INFO  SparkContext - Created broadcast 2043 from broadcast at DAGScheduler.scala:1580
14:05:18.111 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1248 (MapPartitionsRDD[5666] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:05:18.111 INFO  TaskSchedulerImpl - Adding task set 1248.0 with 1 tasks resource profile 0
14:05:18.112 INFO  TaskSetManager - Starting task 0.0 in stage 1248.0 (TID 1072) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9673 bytes) 
14:05:18.112 INFO  Executor - Running task 0.0 in stage 1248.0 (TID 1072)
14:05:18.139 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam:0+5416
14:05:18.144 INFO  Executor - Finished task 0.0 in stage 1248.0 (TID 1072). 1148 bytes result sent to driver
14:05:18.145 INFO  TaskSetManager - Finished task 0.0 in stage 1248.0 (TID 1072) in 33 ms on localhost (executor driver) (1/1)
14:05:18.145 INFO  TaskSchedulerImpl - Removed TaskSet 1248.0, whose tasks have all completed, from pool 
14:05:18.145 INFO  DAGScheduler - ShuffleMapStage 1248 (mapToPair at SparkUtils.java:161) finished in 0.054 s
14:05:18.145 INFO  DAGScheduler - looking for newly runnable stages
14:05:18.145 INFO  DAGScheduler - running: HashSet()
14:05:18.145 INFO  DAGScheduler - waiting: HashSet(ResultStage 1249)
14:05:18.145 INFO  DAGScheduler - failed: HashSet()
14:05:18.145 INFO  DAGScheduler - Submitting ResultStage 1249 (MapPartitionsRDD[5669] at mapPartitions at SparkUtils.java:188), which has no missing parents
14:05:18.145 INFO  MemoryStore - Block broadcast_2044 stored as values in memory (estimated size 7.4 KiB, free 1911.6 MiB)
14:05:18.146 INFO  MemoryStore - Block broadcast_2044_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1911.6 MiB)
14:05:18.146 INFO  BlockManagerInfo - Added broadcast_2044_piece0 in memory on localhost:46769 (size: 4.1 KiB, free: 1918.8 MiB)
14:05:18.146 INFO  SparkContext - Created broadcast 2044 from broadcast at DAGScheduler.scala:1580
14:05:18.146 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1249 (MapPartitionsRDD[5669] at mapPartitions at SparkUtils.java:188) (first 15 tasks are for partitions Vector(0))
14:05:18.146 INFO  TaskSchedulerImpl - Adding task set 1249.0 with 1 tasks resource profile 0
14:05:18.146 INFO  TaskSetManager - Starting task 0.0 in stage 1249.0 (TID 1073) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:18.147 INFO  Executor - Running task 0.0 in stage 1249.0 (TID 1073)
14:05:18.147 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:05:18.147 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.149 INFO  Executor - Finished task 0.0 in stage 1249.0 (TID 1073). 2039 bytes result sent to driver
14:05:18.150 INFO  TaskSetManager - Finished task 0.0 in stage 1249.0 (TID 1073) in 4 ms on localhost (executor driver) (1/1)
14:05:18.150 INFO  TaskSchedulerImpl - Removed TaskSet 1249.0, whose tasks have all completed, from pool 
14:05:18.150 INFO  DAGScheduler - ResultStage 1249 (collect at SparkUtils.java:205) finished in 0.005 s
14:05:18.150 INFO  DAGScheduler - Job 575 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:18.150 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1249: Stage finished
14:05:18.150 INFO  DAGScheduler - Job 575 finished: collect at SparkUtils.java:205, took 0.059689 s
14:05:18.154 INFO  MemoryStore - Block broadcast_2045 stored as values in memory (estimated size 392.0 B, free 1911.6 MiB)
14:05:18.154 INFO  MemoryStore - Block broadcast_2045_piece0 stored as bytes in memory (estimated size 33.0 B, free 1911.6 MiB)
14:05:18.154 INFO  BlockManagerInfo - Added broadcast_2045_piece0 in memory on localhost:46769 (size: 33.0 B, free: 1918.8 MiB)
14:05:18.154 INFO  SparkContext - Created broadcast 2045 from broadcast at MarkDuplicatesSparkUtils.java:126
14:05:18.155 INFO  MemoryStore - Block broadcast_2046 stored as values in memory (estimated size 144.0 B, free 1911.6 MiB)
14:05:18.155 INFO  MemoryStore - Block broadcast_2046_piece0 stored as bytes in memory (estimated size 28.0 B, free 1911.6 MiB)
14:05:18.155 INFO  BlockManagerInfo - Added broadcast_2046_piece0 in memory on localhost:46769 (size: 28.0 B, free: 1918.8 MiB)
14:05:18.155 INFO  SparkContext - Created broadcast 2046 from broadcast at MarkDuplicatesSparkUtils.java:127
14:05:18.167 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
14:05:18.168 INFO  DAGScheduler - Registering RDD 5678 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 310
14:05:18.168 INFO  DAGScheduler - Registering RDD 5682 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 309
14:05:18.168 INFO  DAGScheduler - Registering RDD 5686 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 308
14:05:18.168 INFO  DAGScheduler - Got job 576 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
14:05:18.168 INFO  DAGScheduler - Final stage: ResultStage 1254 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
14:05:18.168 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1253)
14:05:18.168 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1253)
14:05:18.168 INFO  DAGScheduler - Submitting ShuffleMapStage 1251 (MapPartitionsRDD[5678] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
14:05:18.169 INFO  MemoryStore - Block broadcast_2047 stored as values in memory (estimated size 45.2 KiB, free 1911.5 MiB)
14:05:18.170 INFO  MemoryStore - Block broadcast_2047_piece0 stored as bytes in memory (estimated size 17.1 KiB, free 1911.5 MiB)
14:05:18.170 INFO  BlockManagerInfo - Added broadcast_2047_piece0 in memory on localhost:46769 (size: 17.1 KiB, free: 1918.8 MiB)
14:05:18.170 INFO  SparkContext - Created broadcast 2047 from broadcast at DAGScheduler.scala:1580
14:05:18.170 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1251 (MapPartitionsRDD[5678] at flatMapToPair at MarkDuplicatesSparkUtils.java:130) (first 15 tasks are for partitions Vector(0))
14:05:18.170 INFO  TaskSchedulerImpl - Adding task set 1251.0 with 1 tasks resource profile 0
14:05:18.171 INFO  TaskSetManager - Starting task 0.0 in stage 1251.0 (TID 1074) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
14:05:18.171 INFO  Executor - Running task 0.0 in stage 1251.0 (TID 1074)
14:05:18.173 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:05:18.173 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.176 INFO  Executor - Finished task 0.0 in stage 1251.0 (TID 1074). 1922 bytes result sent to driver
14:05:18.177 INFO  TaskSetManager - Finished task 0.0 in stage 1251.0 (TID 1074) in 6 ms on localhost (executor driver) (1/1)
14:05:18.177 INFO  TaskSchedulerImpl - Removed TaskSet 1251.0, whose tasks have all completed, from pool 
14:05:18.177 INFO  DAGScheduler - ShuffleMapStage 1251 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.009 s
14:05:18.177 INFO  DAGScheduler - looking for newly runnable stages
14:05:18.177 INFO  DAGScheduler - running: HashSet()
14:05:18.177 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1252, ShuffleMapStage 1253, ResultStage 1254)
14:05:18.177 INFO  DAGScheduler - failed: HashSet()
14:05:18.177 INFO  DAGScheduler - Submitting ShuffleMapStage 1252 (MapPartitionsRDD[5682] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
14:05:18.178 INFO  MemoryStore - Block broadcast_2048 stored as values in memory (estimated size 49.3 KiB, free 1911.5 MiB)
14:05:18.178 INFO  MemoryStore - Block broadcast_2048_piece0 stored as bytes in memory (estimated size 19.3 KiB, free 1911.4 MiB)
14:05:18.179 INFO  BlockManagerInfo - Added broadcast_2048_piece0 in memory on localhost:46769 (size: 19.3 KiB, free: 1918.8 MiB)
14:05:18.179 INFO  SparkContext - Created broadcast 2048 from broadcast at DAGScheduler.scala:1580
14:05:18.179 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1252 (MapPartitionsRDD[5682] at mapToPair at MarkDuplicatesSpark.java:217) (first 15 tasks are for partitions Vector(0))
14:05:18.179 INFO  TaskSchedulerImpl - Adding task set 1252.0 with 1 tasks resource profile 0
14:05:18.179 INFO  TaskSetManager - Starting task 0.0 in stage 1252.0 (TID 1075) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
14:05:18.179 INFO  Executor - Running task 0.0 in stage 1252.0 (TID 1075)
14:05:18.181 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:05:18.181 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.186 INFO  Executor - Finished task 0.0 in stage 1252.0 (TID 1075). 1922 bytes result sent to driver
14:05:18.186 INFO  TaskSetManager - Finished task 0.0 in stage 1252.0 (TID 1075) in 7 ms on localhost (executor driver) (1/1)
14:05:18.186 INFO  TaskSchedulerImpl - Removed TaskSet 1252.0, whose tasks have all completed, from pool 
14:05:18.186 INFO  DAGScheduler - ShuffleMapStage 1252 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
14:05:18.186 INFO  DAGScheduler - looking for newly runnable stages
14:05:18.186 INFO  DAGScheduler - running: HashSet()
14:05:18.186 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1253, ResultStage 1254)
14:05:18.186 INFO  DAGScheduler - failed: HashSet()
14:05:18.186 INFO  DAGScheduler - Submitting ShuffleMapStage 1253 (MapPartitionsRDD[5686] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
14:05:18.187 INFO  MemoryStore - Block broadcast_2049 stored as values in memory (estimated size 40.0 KiB, free 1911.4 MiB)
14:05:18.187 INFO  MemoryStore - Block broadcast_2049_piece0 stored as bytes in memory (estimated size 14.5 KiB, free 1911.4 MiB)
14:05:18.187 INFO  BlockManagerInfo - Added broadcast_2049_piece0 in memory on localhost:46769 (size: 14.5 KiB, free: 1918.8 MiB)
14:05:18.188 INFO  SparkContext - Created broadcast 2049 from broadcast at DAGScheduler.scala:1580
14:05:18.188 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1253 (MapPartitionsRDD[5686] at mapToPair at MarkDuplicatesSparkUtils.java:497) (first 15 tasks are for partitions Vector(0))
14:05:18.188 INFO  TaskSchedulerImpl - Adding task set 1253.0 with 1 tasks resource profile 0
14:05:18.188 INFO  TaskSetManager - Starting task 0.0 in stage 1253.0 (TID 1076) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:05:18.188 INFO  Executor - Running task 0.0 in stage 1253.0 (TID 1076)
14:05:18.189 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:05:18.189 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.191 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:05:18.191 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.192 INFO  Executor - Finished task 0.0 in stage 1253.0 (TID 1076). 1879 bytes result sent to driver
14:05:18.192 INFO  TaskSetManager - Finished task 0.0 in stage 1253.0 (TID 1076) in 4 ms on localhost (executor driver) (1/1)
14:05:18.192 INFO  TaskSchedulerImpl - Removed TaskSet 1253.0, whose tasks have all completed, from pool 
14:05:18.192 INFO  DAGScheduler - ShuffleMapStage 1253 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
14:05:18.192 INFO  DAGScheduler - looking for newly runnable stages
14:05:18.192 INFO  DAGScheduler - running: HashSet()
14:05:18.192 INFO  DAGScheduler - waiting: HashSet(ResultStage 1254)
14:05:18.192 INFO  DAGScheduler - failed: HashSet()
14:05:18.192 INFO  DAGScheduler - Submitting ResultStage 1254 (MapPartitionsRDD[5688] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
14:05:18.193 INFO  MemoryStore - Block broadcast_2050 stored as values in memory (estimated size 41.2 KiB, free 1911.3 MiB)
14:05:18.194 INFO  MemoryStore - Block broadcast_2050_piece0 stored as bytes in memory (estimated size 15.3 KiB, free 1911.3 MiB)
14:05:18.194 INFO  BlockManagerInfo - Added broadcast_2050_piece0 in memory on localhost:46769 (size: 15.3 KiB, free: 1918.8 MiB)
14:05:18.194 INFO  SparkContext - Created broadcast 2050 from broadcast at DAGScheduler.scala:1580
14:05:18.194 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1254 (MapPartitionsRDD[5688] at mapValues at MarkDuplicatesSparkUtils.java:519) (first 15 tasks are for partitions Vector(0))
14:05:18.194 INFO  TaskSchedulerImpl - Adding task set 1254.0 with 1 tasks resource profile 0
14:05:18.194 INFO  TaskSetManager - Starting task 0.0 in stage 1254.0 (TID 1077) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:18.194 INFO  Executor - Running task 0.0 in stage 1254.0 (TID 1077)
14:05:18.196 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:05:18.196 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.197 INFO  Executor - Finished task 0.0 in stage 1254.0 (TID 1077). 1901 bytes result sent to driver
14:05:18.197 INFO  TaskSetManager - Finished task 0.0 in stage 1254.0 (TID 1077) in 3 ms on localhost (executor driver) (1/1)
14:05:18.197 INFO  TaskSchedulerImpl - Removed TaskSet 1254.0, whose tasks have all completed, from pool 
14:05:18.197 INFO  DAGScheduler - ResultStage 1254 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
14:05:18.197 INFO  DAGScheduler - Job 576 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:18.197 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1254: Stage finished
14:05:18.197 INFO  DAGScheduler - Job 576 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.029808 s
14:05:18.208 INFO  MemoryStore - Block broadcast_2051 stored as values in memory (estimated size 93.5 KiB, free 1911.2 MiB)
14:05:18.208 INFO  MemoryStore - Block broadcast_2051_piece0 stored as bytes in memory (estimated size 5.6 KiB, free 1911.2 MiB)
14:05:18.208 INFO  BlockManagerInfo - Added broadcast_2051_piece0 in memory on localhost:46769 (size: 5.6 KiB, free: 1918.8 MiB)
14:05:18.209 INFO  SparkContext - Created broadcast 2051 from broadcast at ReadsSparkSink.java:133
14:05:18.212 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:05:18.212 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:05:18.212 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:05:18.223 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
14:05:18.223 INFO  DAGScheduler - Registering RDD 5690 (mapToPair at SparkUtils.java:161) as input to shuffle 311
14:05:18.223 INFO  DAGScheduler - Got job 577 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
14:05:18.223 INFO  DAGScheduler - Final stage: ResultStage 1259 (runJob at SparkHadoopWriter.scala:83)
14:05:18.223 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1258)
14:05:18.223 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1258)
14:05:18.223 INFO  DAGScheduler - Submitting ShuffleMapStage 1258 (MapPartitionsRDD[5690] at mapToPair at SparkUtils.java:161), which has no missing parents
14:05:18.224 INFO  MemoryStore - Block broadcast_2052 stored as values in memory (estimated size 39.1 KiB, free 1911.2 MiB)
14:05:18.225 INFO  MemoryStore - Block broadcast_2052_piece0 stored as bytes in memory (estimated size 14.1 KiB, free 1911.2 MiB)
14:05:18.225 INFO  BlockManagerInfo - Added broadcast_2052_piece0 in memory on localhost:46769 (size: 14.1 KiB, free: 1918.8 MiB)
14:05:18.225 INFO  SparkContext - Created broadcast 2052 from broadcast at DAGScheduler.scala:1580
14:05:18.225 INFO  DAGScheduler - Submitting 1 missing tasks from ShuffleMapStage 1258 (MapPartitionsRDD[5690] at mapToPair at SparkUtils.java:161) (first 15 tasks are for partitions Vector(0))
14:05:18.225 INFO  TaskSchedulerImpl - Adding task set 1258.0 with 1 tasks resource profile 0
14:05:18.226 INFO  TaskSetManager - Starting task 0.0 in stage 1258.0 (TID 1078) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
14:05:18.226 INFO  Executor - Running task 0.0 in stage 1258.0 (TID 1078)
14:05:18.227 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:05:18.227 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.229 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:05:18.229 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.230 INFO  Executor - Finished task 0.0 in stage 1258.0 (TID 1078). 1922 bytes result sent to driver
14:05:18.230 INFO  TaskSetManager - Finished task 0.0 in stage 1258.0 (TID 1078) in 4 ms on localhost (executor driver) (1/1)
14:05:18.230 INFO  TaskSchedulerImpl - Removed TaskSet 1258.0, whose tasks have all completed, from pool 
14:05:18.230 INFO  DAGScheduler - ShuffleMapStage 1258 (mapToPair at SparkUtils.java:161) finished in 0.007 s
14:05:18.230 INFO  DAGScheduler - looking for newly runnable stages
14:05:18.230 INFO  DAGScheduler - running: HashSet()
14:05:18.230 INFO  DAGScheduler - waiting: HashSet(ResultStage 1259)
14:05:18.231 INFO  DAGScheduler - failed: HashSet()
14:05:18.231 INFO  DAGScheduler - Submitting ResultStage 1259 (MapPartitionsRDD[5696] at saveAsTextFile at SamSink.java:65), which has no missing parents
14:05:18.237 INFO  MemoryStore - Block broadcast_2053 stored as values in memory (estimated size 183.9 KiB, free 1911.0 MiB)
14:05:18.238 INFO  MemoryStore - Block broadcast_2053_piece0 stored as bytes in memory (estimated size 77.7 KiB, free 1910.9 MiB)
14:05:18.238 INFO  BlockManagerInfo - Added broadcast_2053_piece0 in memory on localhost:46769 (size: 77.7 KiB, free: 1918.7 MiB)
14:05:18.238 INFO  SparkContext - Created broadcast 2053 from broadcast at DAGScheduler.scala:1580
14:05:18.238 INFO  DAGScheduler - Submitting 1 missing tasks from ResultStage 1259 (MapPartitionsRDD[5696] at saveAsTextFile at SamSink.java:65) (first 15 tasks are for partitions Vector(0))
14:05:18.238 INFO  TaskSchedulerImpl - Adding task set 1259.0 with 1 tasks resource profile 0
14:05:18.239 INFO  TaskSetManager - Starting task 0.0 in stage 1259.0 (TID 1079) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
14:05:18.239 INFO  Executor - Running task 0.0 in stage 1259.0 (TID 1079)
14:05:18.242 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:05:18.242 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
14:05:18.243 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
14:05:18.244 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
14:05:18.244 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
14:05:18.250 INFO  FileOutputCommitter - Saved output of task 'attempt_202505271405183575953170375822435_5696_m_000000_0' to file:/tmp/MarkDups805512081744583897/MarkDups.sam.parts/_temporary/0/task_202505271405183575953170375822435_5696_m_000000
14:05:18.250 INFO  SparkHadoopMapRedUtil - attempt_202505271405183575953170375822435_5696_m_000000_0: Committed. Elapsed time: 0 ms.
14:05:18.250 INFO  Executor - Finished task 0.0 in stage 1259.0 (TID 1079). 1858 bytes result sent to driver
14:05:18.250 INFO  TaskSetManager - Finished task 0.0 in stage 1259.0 (TID 1079) in 11 ms on localhost (executor driver) (1/1)
14:05:18.250 INFO  TaskSchedulerImpl - Removed TaskSet 1259.0, whose tasks have all completed, from pool 
14:05:18.250 INFO  DAGScheduler - ResultStage 1259 (runJob at SparkHadoopWriter.scala:83) finished in 0.019 s
14:05:18.250 INFO  DAGScheduler - Job 577 is finished. Cancelling potential speculative or zombie tasks for this job
14:05:18.250 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1259: Stage finished
14:05:18.250 INFO  DAGScheduler - Job 577 finished: runJob at SparkHadoopWriter.scala:83, took 0.027726 s
14:05:18.250 INFO  SparkHadoopWriter - Start to commit write Job job_202505271405183575953170375822435_5696.
14:05:18.253 INFO  SparkHadoopWriter - Write Job job_202505271405183575953170375822435_5696 committed. Elapsed time: 2 ms.
14:05:18.257 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups805512081744583897/MarkDups.sam
14:05:18.259 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups805512081744583897/MarkDups.sam done
14:05:18.260 INFO  MarkDuplicatesSpark - Shutting down engine
[May 27, 2025 at 2:05:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
14:05:23.953 ERROR Executor - Exception in task 0.0 in stage 1479.0 (TID 1226)
org.broadinstitute.hellbender.exceptions.UserException$ReadMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 is missing the read group (RG) tag, which is required by the GATK.  Please use http://gatkforums.broadinstitute.org/discussion/59/companion-utilities-replacereadgroups to fix this problem
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:64) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
14:05:23.966 ERROR TaskSetManager - Task 0 in stage 1479.0 failed 1 times; aborting job
[May 27, 2025 at 2:05:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
14:05:24.203 ERROR Executor - Exception in task 0.0 in stage 1486.0 (TID 1229)
org.broadinstitute.hellbender.exceptions.UserException$HeaderMissingReadGroup: SAM/BAM/CRAM file (unknown) is malformed: Read RUNID:7:1203:2886:82292 contains an (RG) tag with the group NotADuplicateGroup which is not found in the file header.
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.getLibraryForRead(MarkDuplicatesSparkUtils.java:66) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at java.base/java.util.stream.ReferencePipeline$15$1.accept(ReferencePipeline.java:540) ~[?:?]
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[?:?]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
	at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682) ~[?:?]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$5ac2632f$1(MarkDuplicatesSparkUtils.java:150) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-5c95f6f-SNAPSHOT-local.jar:5c95f6f-SNAPSHOT]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
	at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
14:05:24.205 ERROR TaskSetManager - Task 0 in stage 1486.0 failed 1 times; aborting job
[May 27, 2025 at 2:05:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:41 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:46 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808
[May 27, 2025 at 2:05:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1528823808