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

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

tests
0

failures
0

ignored
1m0.45s

duration
100%

successful

Tests

Test Duration Result
assertThatExpectedOutputUpdateToggleIsDisabled 0s passed
testAssertAssumeUnsortedFilesAreQueryGroupedFiles 0.543s passed
testAssertCorrectSortOrderMultipleBams 0.148s passed
testAssertCorrectSortOrderMultipleBamsOverriding 0.499s passed
testBulkFragmentsNoDuplicates 1.074s passed
testBulkFragmentsWithDuplicates 2.141s passed
testDifferentChromosomesInOppositeOrder 0.321s 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.271s passed
testDuplicateDetectionDataProviderWithMetrics[1](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.picard-2.15.0.sorted.optical_dupes.markDuplicate.metrics) 0.250s passed
testDuplicateDetectionDataProviderWithMetrics[2](src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam, src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/expected.picard-2.15.0.sorted.inputSingleLibrarySolexa16404.metrics) 0.251s passed
testFlowModeFlag 1.673s passed
testHashCollisionHandling 1.030s 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.278s 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.279s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[0](true, true, true) 0.335s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[1](true, false, true) 0.318s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[2](false, true, true) 0.317s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[3](true, true, false) 0.303s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[4](true, false, false) 0.323s passed
testManyOpticalDuplicateClusterOneEndSamePositionOneCluster[5](false, true, false) 0.314s passed
testMappedFragmentAndMappedPairFirstOfPairNonPrimary 0.317s passed
testMappedFragmentAndMatePairFirstUnmapped 0.317s passed
testMappedFragmentAndMatePairSecondUnmapped 0.300s passed
testMappedPairAndMappedFragmentAndMatePairFirstUnmapped 0.307s passed
testMappedPairAndMappedFragmentAndMatePairSecondUnmapped 0.318s passed
testMappedPairAndMatePairFirstOppositeStrandSecondUnmapped 0.307s passed
testMappedPairAndMatePairFirstUnmapped 0.309s passed
testMappedPairAndMatePairSecondUnmapped 0.302s passed
testMappedPairWithFirstEndSamePositionAndOther 0.309s passed
testMappedPairWithSamePosition 0.306s passed
testMappedPairWithSamePositionSameCigar 0.309s passed
testMarkDuplicatesSparkDeletingDuplicateReads[0]([Ljava.io.File;@59002daa, 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.351s passed
testMarkDuplicatesSparkDeletingDuplicateReads[1]([Ljava.io.File;@4aba9704, 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.360s passed
testMarkDuplicatesSparkDeletingDuplicateReads[2]([Ljava.io.File;@71f2b12d, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.374s passed
testMarkDuplicatesSparkDeletingDuplicateReads[3]([Ljava.io.File;@6769a486, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.335s passed
testMarkDuplicatesSparkDeletingDuplicateReads[4]([Ljava.io.File;@76b89abc, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.339s passed
testMarkDuplicatesSparkDeletingDuplicateReads[5]([Ljava.io.File;@29a2c491, 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.190s passed
testMarkDuplicatesSparkDeletingDuplicateReads[6]([Ljava.io.File;@37545110, 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.221s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[0]([Ljava.io.File;@722c91ca, 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.368s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[1]([Ljava.io.File;@30999cf, 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.350s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[2]([Ljava.io.File;@28334f90, 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.358s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[3]([Ljava.io.File;@17809ed7, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.335s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[4]([Ljava.io.File;@37dc5cb4, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.343s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[5]([Ljava.io.File;@435d2c70, 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.193s passed
testMarkDuplicatesSparkDeletingOpticalDuplicateReads[6]([Ljava.io.File;@50826f9f, 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.157s passed
testMarkDuplicatesSparkIntegrationTestLocal[0]([Ljava.io.File;@6b3c06fc, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]}) 0.329s passed
testMarkDuplicatesSparkIntegrationTestLocal[1]([Ljava.io.File;@4678b390, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.351s passed
testMarkDuplicatesSparkIntegrationTestLocal[2]([Ljava.io.File;@dbdac72, 90, 6, {Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 0.362s passed
testMarkDuplicatesSparkIntegrationTestLocal[3]([Ljava.io.File;@71bb5c2, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.308s passed
testMarkDuplicatesSparkIntegrationTestLocal[4]([Ljava.io.File;@3daed2a5, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.329s passed
testMarkDuplicatesSparkIntegrationTestLocal[5]([Ljava.io.File;@63d8b56e, 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.170s passed
testMarkDuplicatesSparkIntegrationTestLocal[6]([Ljava.io.File;@1cc1b097, 94, 8, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0], Solexa-16419=[4, 4, 4, 0, 0, 0, 0.0, 0], Solexa-16416=[2, 2, 2, 0, 0, 0, 0.0, 0], Solexa-16404=[3, 9, 3, 0, 2, 0, 0.190476, 17], Solexa-16406=[1, 10, 1, 0, 0, 0, 0.0, 0], Solexa-16412=[3, 6, 3, 0, 1, 0, 0.133333, 15]}) 1.129s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[0]([Ljava.io.File;@598287f0, 20, 0, {Solexa-16419=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16416=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16404=[0, 3, 0, 0, 0, 0, 0.0, 0], Solexa-16406=[0, 1, 0, 0, 0, 0, 0.0, 0], Solexa-16412=[0, 1, 0, 0, 0, 0, 0.0, 0]}) 0.345s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[1]([Ljava.io.File;@251c503f, 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.343s 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.349s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[3]([Ljava.io.File;@df1f0c5, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.318s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[4]([Ljava.io.File;@791f270d, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.306s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[5]([Ljava.io.File;@7a67bac2, 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.162s passed
testMarkDuplicatesSparkMarkingAllDuplicatesWithTagging[6]([Ljava.io.File;@38266b3a, 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.197s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[0]([Ljava.io.File;@6142abde, 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.341s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[1]([Ljava.io.File;@122713d6, 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.343s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[2]([Ljava.io.File;@5e792f38, 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.349s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[3]([Ljava.io.File;@600de63a, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.341s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[4]([Ljava.io.File;@515e4df5, 4, 2, {mylib=[0, 2, 0, 0, 1, 1, 0.5, 0]}) 0.322s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[5]([Ljava.io.File;@10851d4b, 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.173s passed
testMarkDuplicatesSparkMarkingOpticalDuplicatesWithTagging[6]([Ljava.io.File;@31f758a2, 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.187s passed
testMatePairFirstUnmapped 0.313s passed
testMatePairSecondUnmapped 0.307s passed
testNoReadGroupInRead 0.255s passed
testNonExistantReadGroupInRead 0.241s passed
testNullOpticalDuplicates 0.311s passed
testOpticalDuplicateClusterOneEndSamePositionOneCluster 0.310s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicatesWithinPixelDistance 0.309s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.329s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.298s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.311s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.311s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.305s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.304s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.308s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.315s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.310s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.314s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.298s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.313s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.301s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.308s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.304s passed
testOpticalDuplicateClusterSamePositionNoOpticalDuplicates[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.312s passed
testOpticalDuplicateClusterSamePositionOneOpticalDuplicatesWithinPixelDistance 0.300s passed
testOpticalDuplicateClustersAddingSecondEndFirstSameCoordinate 0.310s passed
testOpticalDuplicateFinding 0.300s passed
testOpticalDuplicateFindingPxelDistance 0.310s passed
testOpticalDuplicatesAndPCRDuplicatesOrientationDifference 0.298s passed
testOpticalDuplicatesDifferentReadGroups 0.306s passed
testOpticalDuplicatesTheSameReadGroup 0.301s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[0](RUNID:7:1203:2886:82292, RUNID:7:1205:3886:16834) 0.299s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[10](RUNID:7:1203:6886:16756, RUNID:7:1203:4886:26756) 0.313s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[11](RUNID:7:1203:2886:34756, RUNID:7:1203:2886:36756) 0.310s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[12](RUNID:7:1203:2886:35756, RUNID:7:1203:2886:36756) 0.305s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[13](RUNID:7:1203:2886:37756, RUNID:7:1203:2886:36756) 0.304s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[14](RUNID:7:1203:2886:38756, RUNID:7:1203:2886:36756) 0.306s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[15](HK3T5CCXX160204:3:1112:11586:37067, HK3T5CCXX160204:3:1112:11586:32144) 0.295s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[1](RUNID:7:1203:2886:16756, RUNID:7:1205:3886:16756) 0.305s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[2](RUNID:7:1204:2886:16756, RUNID:7:1205:3886:16756) 0.304s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[3](RUNID:7:1205:2886:16756, RUNID:7:1205:3886:16756) 0.305s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[4](RUNID:7:1206:2886:16756, RUNID:7:1205:3886:16756) 0.309s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[5](RUNID:7:1207:2886:16756, RUNID:7:1205:3886:16756) 0.309s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[6](RUNID:7:1203:2886:16756, RUNID:7:1203:4886:26756) 0.297s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[7](RUNID:7:1203:3886:16756, RUNID:7:1203:4886:26756) 0.310s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[8](RUNID:7:1203:4886:16756, RUNID:7:1203:4886:26756) 0.306s passed
testOpticalDuplicatesTiebrokenByPhysicalLocationNotStartPosition[9](RUNID:7:1203:5886:16756, RUNID:7:1203:4886:26756) 0.307s passed
testPathologicalOrderingAtTheSamePosition 0.306s passed
testReadSameStartPositionOrientationOverride 0.300s passed
testReadsHaveSameStartPositionButDifferentChromosomeNonEquivalence 0.316s passed
testSecondEndIsBeforeFirstInCoordinate 0.306s passed
testSingleMappedFragment 0.307s passed
testSingleMappedFragmentAndSingleMappedPair 0.313s passed
testSingleMappedFragmentAndTwoMappedPairs 0.302s passed
testSingleMappedPair 0.304s passed
testSingleUnmappedFragment 0.290s passed
testSingleUnmappedPair 0.296s passed
testStackOverFlowPairSetSwap 0.300s passed
testSupplementaryReadUnmappedMate 0.314s passed
testThreeGroupsOnDifferentChromosomesOfThreeMappedPairs 0.302s passed
testThreeMappedPairs 0.302s passed
testThreeMappedPairsWithMatchingSecondMate 0.300s passed
testTwoGroupsOnDifferentChromosomesOfThreeMappedPairs 0.302s passed
testTwoGroupsOnDifferentChromosomesOfTwoFragments 0.311s passed
testTwoGroupsOnDifferentChromosomesOfTwoMappedPairs 0.330s passed
testTwoMappedFragments 0.314s passed
testTwoMappedPairWithSamePosition 0.292s passed
testTwoMappedPairWithSamePositionDifferentStrands 0.297s passed
testTwoMappedPairWithSamePositionDifferentStrands2 0.291s passed
testTwoMappedPairs 0.296s passed
testTwoMappedPairsAndMappedSecondaryFragment 0.288s passed
testTwoMappedPairsAndTerminalUnmappedFragment 0.299s passed
testTwoMappedPairsAndTerminalUnmappedPair 0.294s passed
testTwoMappedPairsMatesSoftClipped 0.302s passed
testTwoMappedPairsWithOppositeOrientations 0.303s passed
testTwoMappedPairsWithOppositeOrientationsNumberTwo 0.291s passed
testTwoMappedPairsWithSoftClipping 0.305s passed
testTwoMappedPairsWithSoftClippingBoth 0.298s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnly 0.300s passed
testTwoMappedPairsWithSoftClippingFirstOfPairOnlyNoMateCigar 0.300s passed
testTwoMappedPairsWithSupplementaryReads[0](true, true, true) 0.302s passed
testTwoMappedPairsWithSupplementaryReads[1](true, false, true) 0.291s passed
testTwoMappedPairsWithSupplementaryReads[2](false, true, true) 0.302s passed
testTwoMappedPairsWithSupplementaryReads[3](true, true, false) 0.300s passed
testTwoMappedPairsWithSupplementaryReads[4](true, false, false) 0.301s passed
testTwoMappedPairsWithSupplementaryReads[5](false, true, false) 0.301s passed
testTwoUnmappedFragments 0.293s passed

Standard error

[May 19, 2025 at 4:01:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:39 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:40 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
16:01:42.052 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:01:42.052 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) va6bd333-SNAPSHOT
16:01:42.052 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
16:01:42.052 INFO  MarkDuplicatesSpark - Executing as root@67ac59543751 on Linux v6.11.0-1014-azure amd64
16:01:42.052 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
16:01:42.052 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 4:01:42 PM GMT
16:01:42.052 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:01:42.052 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:01:42.053 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
16:01:42.053 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
16:01:42.053 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
16:01:42.053 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:01:42.053 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:01:42.053 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:01:42.053 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:01:42.053 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
16:01:42.053 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
16:01:42.053 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
16:01:42.053 INFO  MarkDuplicatesSpark - Requester pays: disabled
16:01:42.053 INFO  MarkDuplicatesSpark - Initializing engine
16:01:42.053 INFO  MarkDuplicatesSpark - Done initializing engine
16:01:42.053 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
16:01:42.056 INFO  MemoryStore - Block broadcast_1411 stored as values in memory (estimated size 305.5 KiB, free 1903.3 MiB)
16:01:42.062 INFO  MemoryStore - Block broadcast_1411_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1903.2 MiB)
16:01:42.063 INFO  BlockManagerInfo - Added broadcast_1411_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1918.9 MiB)
16:01:42.063 INFO  SparkContext - Created broadcast 1411 from newAPIHadoopFile at PathSplitSource.java:96
16:01:42.083 INFO  MemoryStore - Block broadcast_1412 stored as values in memory (estimated size 305.5 KiB, free 1902.9 MiB)
16:01:42.089 INFO  MemoryStore - Block broadcast_1412_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1902.9 MiB)
16:01:42.089 INFO  BlockManagerInfo - Added broadcast_1412_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1918.9 MiB)
16:01:42.089 INFO  SparkContext - Created broadcast 1412 from newAPIHadoopFile at PathSplitSource.java:96
16:01:42.121 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
16:01:42.122 INFO  FileInputFormat - Total input files to process : 1
16:01:42.122 INFO  DAGScheduler - Registering RDD 3614 (mapToPair at SparkUtils.java:161) as input to shuffle 97
16:01:42.123 INFO  DAGScheduler - Got job 433 (collect at SparkUtils.java:205) with 1 output partitions
16:01:42.123 INFO  DAGScheduler - Final stage: ResultStage 741 (collect at SparkUtils.java:205)
16:01:42.123 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 740)
16:01:42.123 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 740)
16:01:42.123 INFO  DAGScheduler - Submitting ShuffleMapStage 740 (MapPartitionsRDD[3614] at mapToPair at SparkUtils.java:161), which has no missing parents
16:01:42.140 INFO  MemoryStore - Block broadcast_1413 stored as values in memory (estimated size 459.2 KiB, free 1902.4 MiB)
16:01:42.142 INFO  MemoryStore - Block broadcast_1413_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1902.2 MiB)
16:01:42.143 INFO  BlockManagerInfo - Added broadcast_1413_piece0 in memory on localhost:42397 (size: 201.4 KiB, free: 1918.7 MiB)
16:01:42.143 INFO  SparkContext - Created broadcast 1413 from broadcast at DAGScheduler.scala:1580
16:01:42.143 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))
16:01:42.143 INFO  TaskSchedulerImpl - Adding task set 740.0 with 1 tasks resource profile 0
16:01:42.144 INFO  TaskSetManager - Starting task 0.0 in stage 740.0 (TID 670) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9650 bytes) 
16:01:42.145 INFO  Executor - Running task 0.0 in stage 740.0 (TID 670)
16:01:42.173 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug.bam:0+1507
16:01:42.177 INFO  Executor - Finished task 0.0 in stage 740.0 (TID 670). 1148 bytes result sent to driver
16:01:42.178 INFO  TaskSetManager - Finished task 0.0 in stage 740.0 (TID 670) in 34 ms on localhost (executor driver) (1/1)
16:01:42.178 INFO  TaskSchedulerImpl - Removed TaskSet 740.0, whose tasks have all completed, from pool 
16:01:42.178 INFO  DAGScheduler - ShuffleMapStage 740 (mapToPair at SparkUtils.java:161) finished in 0.054 s
16:01:42.178 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.178 INFO  DAGScheduler - running: HashSet()
16:01:42.178 INFO  DAGScheduler - waiting: HashSet(ResultStage 741)
16:01:42.178 INFO  DAGScheduler - failed: HashSet()
16:01:42.178 INFO  DAGScheduler - Submitting ResultStage 741 (MapPartitionsRDD[3617] at mapPartitions at SparkUtils.java:188), which has no missing parents
16:01:42.179 INFO  MemoryStore - Block broadcast_1414 stored as values in memory (estimated size 7.4 KiB, free 1902.2 MiB)
16:01:42.179 INFO  MemoryStore - Block broadcast_1414_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1902.2 MiB)
16:01:42.180 INFO  BlockManagerInfo - Added broadcast_1414_piece0 in memory on localhost:42397 (size: 4.1 KiB, free: 1918.7 MiB)
16:01:42.180 INFO  SparkContext - Created broadcast 1414 from broadcast at DAGScheduler.scala:1580
16:01:42.180 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))
16:01:42.180 INFO  TaskSchedulerImpl - Adding task set 741.0 with 1 tasks resource profile 0
16:01:42.181 INFO  TaskSetManager - Starting task 0.0 in stage 741.0 (TID 671) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:01:42.181 INFO  Executor - Running task 0.0 in stage 741.0 (TID 671)
16:01:42.182 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
16:01:42.182 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.184 INFO  Executor - Finished task 0.0 in stage 741.0 (TID 671). 2238 bytes result sent to driver
16:01:42.184 INFO  TaskSetManager - Finished task 0.0 in stage 741.0 (TID 671) in 4 ms on localhost (executor driver) (1/1)
16:01:42.184 INFO  TaskSchedulerImpl - Removed TaskSet 741.0, whose tasks have all completed, from pool 
16:01:42.185 INFO  DAGScheduler - ResultStage 741 (collect at SparkUtils.java:205) finished in 0.005 s
16:01:42.185 INFO  DAGScheduler - Job 433 is finished. Cancelling potential speculative or zombie tasks for this job
16:01:42.185 INFO  TaskSchedulerImpl - Killing all running tasks in stage 741: Stage finished
16:01:42.185 INFO  DAGScheduler - Job 433 finished: collect at SparkUtils.java:205, took 0.063488 s
16:01:42.189 INFO  MemoryStore - Block broadcast_1415 stored as values in memory (estimated size 1632.0 B, free 1902.2 MiB)
16:01:42.189 INFO  MemoryStore - Block broadcast_1415_piece0 stored as bytes in memory (estimated size 145.0 B, free 1902.2 MiB)
16:01:42.190 INFO  BlockManagerInfo - Added broadcast_1415_piece0 in memory on localhost:42397 (size: 145.0 B, free: 1918.7 MiB)
16:01:42.190 INFO  SparkContext - Created broadcast 1415 from broadcast at MarkDuplicatesSparkUtils.java:126
16:01:42.190 INFO  MemoryStore - Block broadcast_1416 stored as values in memory (estimated size 304.0 B, free 1902.2 MiB)
16:01:42.190 INFO  MemoryStore - Block broadcast_1416_piece0 stored as bytes in memory (estimated size 37.0 B, free 1902.2 MiB)
16:01:42.191 INFO  BlockManagerInfo - Added broadcast_1416_piece0 in memory on localhost:42397 (size: 37.0 B, free: 1918.7 MiB)
16:01:42.191 INFO  SparkContext - Created broadcast 1416 from broadcast at MarkDuplicatesSparkUtils.java:127
16:01:42.202 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
16:01:42.203 INFO  DAGScheduler - Registering RDD 3626 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 100
16:01:42.203 INFO  DAGScheduler - Registering RDD 3630 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 99
16:01:42.203 INFO  DAGScheduler - Registering RDD 3634 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 98
16:01:42.203 INFO  DAGScheduler - Got job 434 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
16:01:42.203 INFO  DAGScheduler - Final stage: ResultStage 746 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
16:01:42.203 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 745)
16:01:42.204 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 745)
16:01:42.204 INFO  DAGScheduler - Submitting ShuffleMapStage 743 (MapPartitionsRDD[3626] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
16:01:42.205 INFO  MemoryStore - Block broadcast_1417 stored as values in memory (estimated size 24.2 KiB, free 1902.2 MiB)
16:01:42.205 INFO  MemoryStore - Block broadcast_1417_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1902.2 MiB)
16:01:42.205 INFO  BlockManagerInfo - Added broadcast_1417_piece0 in memory on localhost:42397 (size: 12.6 KiB, free: 1918.6 MiB)
16:01:42.206 INFO  SparkContext - Created broadcast 1417 from broadcast at DAGScheduler.scala:1580
16:01:42.206 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))
16:01:42.206 INFO  TaskSchedulerImpl - Adding task set 743.0 with 1 tasks resource profile 0
16:01:42.206 INFO  TaskSetManager - Starting task 0.0 in stage 743.0 (TID 672) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
16:01:42.207 INFO  Executor - Running task 0.0 in stage 743.0 (TID 672)
16:01:42.208 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
16:01:42.208 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.211 INFO  Executor - Finished task 0.0 in stage 743.0 (TID 672). 1922 bytes result sent to driver
16:01:42.211 INFO  TaskSetManager - Finished task 0.0 in stage 743.0 (TID 672) in 5 ms on localhost (executor driver) (1/1)
16:01:42.212 INFO  TaskSchedulerImpl - Removed TaskSet 743.0, whose tasks have all completed, from pool 
16:01:42.212 INFO  DAGScheduler - ShuffleMapStage 743 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
16:01:42.212 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.212 INFO  DAGScheduler - running: HashSet()
16:01:42.212 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 744, ShuffleMapStage 745, ResultStage 746)
16:01:42.212 INFO  DAGScheduler - failed: HashSet()
16:01:42.212 INFO  DAGScheduler - Submitting ShuffleMapStage 744 (MapPartitionsRDD[3630] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
16:01:42.213 INFO  MemoryStore - Block broadcast_1418 stored as values in memory (estimated size 28.3 KiB, free 1902.1 MiB)
16:01:42.213 INFO  MemoryStore - Block broadcast_1418_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1902.1 MiB)
16:01:42.214 INFO  BlockManagerInfo - Added broadcast_1418_piece0 in memory on localhost:42397 (size: 14.8 KiB, free: 1918.6 MiB)
16:01:42.214 INFO  SparkContext - Created broadcast 1418 from broadcast at DAGScheduler.scala:1580
16:01:42.214 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))
16:01:42.214 INFO  TaskSchedulerImpl - Adding task set 744.0 with 1 tasks resource profile 0
16:01:42.214 INFO  TaskSetManager - Starting task 0.0 in stage 744.0 (TID 673) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
16:01:42.215 INFO  Executor - Running task 0.0 in stage 744.0 (TID 673)
16:01:42.217 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
16:01:42.217 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.220 INFO  Executor - Finished task 0.0 in stage 744.0 (TID 673). 1922 bytes result sent to driver
16:01:42.220 INFO  TaskSetManager - Finished task 0.0 in stage 744.0 (TID 673) in 6 ms on localhost (executor driver) (1/1)
16:01:42.220 INFO  TaskSchedulerImpl - Removed TaskSet 744.0, whose tasks have all completed, from pool 
16:01:42.220 INFO  DAGScheduler - ShuffleMapStage 744 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.008 s
16:01:42.221 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.221 INFO  DAGScheduler - running: HashSet()
16:01:42.221 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 745, ResultStage 746)
16:01:42.221 INFO  DAGScheduler - failed: HashSet()
16:01:42.221 INFO  DAGScheduler - Submitting ShuffleMapStage 745 (MapPartitionsRDD[3634] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
16:01:42.222 INFO  MemoryStore - Block broadcast_1419 stored as values in memory (estimated size 19.0 KiB, free 1902.1 MiB)
16:01:42.222 INFO  MemoryStore - Block broadcast_1419_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1902.1 MiB)
16:01:42.222 INFO  BlockManagerInfo - Added broadcast_1419_piece0 in memory on localhost:42397 (size: 9.7 KiB, free: 1918.6 MiB)
16:01:42.222 INFO  SparkContext - Created broadcast 1419 from broadcast at DAGScheduler.scala:1580
16:01:42.222 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))
16:01:42.223 INFO  TaskSchedulerImpl - Adding task set 745.0 with 1 tasks resource profile 0
16:01:42.223 INFO  TaskSetManager - Starting task 0.0 in stage 745.0 (TID 674) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:01:42.223 INFO  Executor - Running task 0.0 in stage 745.0 (TID 674)
16:01:42.225 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
16:01:42.225 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.226 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
16:01:42.226 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.228 INFO  Executor - Finished task 0.0 in stage 745.0 (TID 674). 1922 bytes result sent to driver
16:01:42.228 INFO  TaskSetManager - Finished task 0.0 in stage 745.0 (TID 674) in 5 ms on localhost (executor driver) (1/1)
16:01:42.228 INFO  TaskSchedulerImpl - Removed TaskSet 745.0, whose tasks have all completed, from pool 
16:01:42.228 INFO  DAGScheduler - ShuffleMapStage 745 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.007 s
16:01:42.228 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.228 INFO  DAGScheduler - running: HashSet()
16:01:42.229 INFO  DAGScheduler - waiting: HashSet(ResultStage 746)
16:01:42.229 INFO  DAGScheduler - failed: HashSet()
16:01:42.229 INFO  DAGScheduler - Submitting ResultStage 746 (MapPartitionsRDD[3636] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
16:01:42.229 INFO  MemoryStore - Block broadcast_1420 stored as values in memory (estimated size 20.2 KiB, free 1902.1 MiB)
16:01:42.230 INFO  MemoryStore - Block broadcast_1420_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1902.1 MiB)
16:01:42.230 INFO  BlockManagerInfo - Added broadcast_1420_piece0 in memory on localhost:42397 (size: 10.6 KiB, free: 1918.6 MiB)
16:01:42.230 INFO  SparkContext - Created broadcast 1420 from broadcast at DAGScheduler.scala:1580
16:01:42.230 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))
16:01:42.230 INFO  TaskSchedulerImpl - Adding task set 746.0 with 1 tasks resource profile 0
16:01:42.231 INFO  TaskSetManager - Starting task 0.0 in stage 746.0 (TID 675) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:01:42.231 INFO  Executor - Running task 0.0 in stage 746.0 (TID 675)
16:01:42.232 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
16:01:42.232 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.234 INFO  Executor - Finished task 0.0 in stage 746.0 (TID 675). 1901 bytes result sent to driver
16:01:42.234 INFO  TaskSetManager - Finished task 0.0 in stage 746.0 (TID 675) in 3 ms on localhost (executor driver) (1/1)
16:01:42.234 INFO  TaskSchedulerImpl - Removed TaskSet 746.0, whose tasks have all completed, from pool 
16:01:42.234 INFO  DAGScheduler - ResultStage 746 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
16:01:42.234 INFO  DAGScheduler - Job 434 is finished. Cancelling potential speculative or zombie tasks for this job
16:01:42.234 INFO  TaskSchedulerImpl - Killing all running tasks in stage 746: Stage finished
16:01:42.234 INFO  DAGScheduler - Job 434 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.031984 s
16:01:42.244 INFO  MemoryStore - Block broadcast_1421 stored as values in memory (estimated size 20.3 KiB, free 1902.0 MiB)
16:01:42.245 INFO  MemoryStore - Block broadcast_1421_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1902.0 MiB)
16:01:42.245 INFO  BlockManagerInfo - Added broadcast_1421_piece0 in memory on localhost:42397 (size: 1850.0 B, free: 1918.6 MiB)
16:01:42.245 INFO  SparkContext - Created broadcast 1421 from broadcast at ReadsSparkSink.java:133
16:01:42.246 INFO  MemoryStore - Block broadcast_1422 stored as values in memory (estimated size 20.4 KiB, free 1902.0 MiB)
16:01:42.246 INFO  MemoryStore - Block broadcast_1422_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1902.0 MiB)
16:01:42.246 INFO  BlockManagerInfo - Added broadcast_1422_piece0 in memory on localhost:42397 (size: 1850.0 B, free: 1918.6 MiB)
16:01:42.246 INFO  SparkContext - Created broadcast 1422 from broadcast at BamSink.java:76
16:01:42.248 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
16:01:42.248 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:01:42.248 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:01:42.259 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
16:01:42.259 INFO  DAGScheduler - Registering RDD 3638 (mapToPair at SparkUtils.java:161) as input to shuffle 101
16:01:42.260 INFO  DAGScheduler - Got job 435 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
16:01:42.260 INFO  DAGScheduler - Final stage: ResultStage 751 (runJob at SparkHadoopWriter.scala:83)
16:01:42.260 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 750)
16:01:42.260 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 750)
16:01:42.260 INFO  DAGScheduler - Submitting ShuffleMapStage 750 (MapPartitionsRDD[3638] at mapToPair at SparkUtils.java:161), which has no missing parents
16:01:42.261 INFO  MemoryStore - Block broadcast_1423 stored as values in memory (estimated size 18.1 KiB, free 1902.0 MiB)
16:01:42.261 INFO  MemoryStore - Block broadcast_1423_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1902.0 MiB)
16:01:42.261 INFO  BlockManagerInfo - Added broadcast_1423_piece0 in memory on localhost:42397 (size: 9.5 KiB, free: 1918.6 MiB)
16:01:42.261 INFO  SparkContext - Created broadcast 1423 from broadcast at DAGScheduler.scala:1580
16:01:42.262 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))
16:01:42.262 INFO  TaskSchedulerImpl - Adding task set 750.0 with 1 tasks resource profile 0
16:01:42.262 INFO  TaskSetManager - Starting task 0.0 in stage 750.0 (TID 676) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:01:42.262 INFO  Executor - Running task 0.0 in stage 750.0 (TID 676)
16:01:42.264 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
16:01:42.264 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.266 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
16:01:42.266 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.267 INFO  Executor - Finished task 0.0 in stage 750.0 (TID 676). 1879 bytes result sent to driver
16:01:42.267 INFO  TaskSetManager - Finished task 0.0 in stage 750.0 (TID 676) in 5 ms on localhost (executor driver) (1/1)
16:01:42.268 INFO  TaskSchedulerImpl - Removed TaskSet 750.0, whose tasks have all completed, from pool 
16:01:42.268 INFO  DAGScheduler - ShuffleMapStage 750 (mapToPair at SparkUtils.java:161) finished in 0.008 s
16:01:42.268 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.268 INFO  DAGScheduler - running: HashSet()
16:01:42.268 INFO  DAGScheduler - waiting: HashSet(ResultStage 751)
16:01:42.268 INFO  DAGScheduler - failed: HashSet()
16:01:42.268 INFO  DAGScheduler - Submitting ResultStage 751 (MapPartitionsRDD[3643] at mapToPair at BamSink.java:91), which has no missing parents
16:01:42.274 INFO  MemoryStore - Block broadcast_1424 stored as values in memory (estimated size 163.3 KiB, free 1901.8 MiB)
16:01:42.275 INFO  MemoryStore - Block broadcast_1424_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1901.8 MiB)
16:01:42.275 INFO  BlockManagerInfo - Added broadcast_1424_piece0 in memory on localhost:42397 (size: 73.4 KiB, free: 1918.5 MiB)
16:01:42.276 INFO  SparkContext - Created broadcast 1424 from broadcast at DAGScheduler.scala:1580
16:01:42.276 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))
16:01:42.276 INFO  TaskSchedulerImpl - Adding task set 751.0 with 1 tasks resource profile 0
16:01:42.276 INFO  TaskSetManager - Starting task 0.0 in stage 751.0 (TID 677) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:01:42.276 INFO  Executor - Running task 0.0 in stage 751.0 (TID 677)
16:01:42.280 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
16:01:42.280 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.282 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
16:01:42.282 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:01:42.282 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:01:42.282 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
16:01:42.282 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:01:42.282 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:01:42.292 INFO  FileOutputCommitter - Saved output of task 'attempt_20250519160142968355963334720284_3643_r_000000_0' to file:/tmp/local13774000465916765003/markdups2178781706614791083.bam.parts/_temporary/0/task_20250519160142968355963334720284_3643_r_000000
16:01:42.292 INFO  SparkHadoopMapRedUtil - attempt_20250519160142968355963334720284_3643_r_000000_0: Committed. Elapsed time: 0 ms.
16:01:42.292 INFO  Executor - Finished task 0.0 in stage 751.0 (TID 677). 1858 bytes result sent to driver
16:01:42.292 INFO  TaskSetManager - Finished task 0.0 in stage 751.0 (TID 677) in 16 ms on localhost (executor driver) (1/1)
16:01:42.292 INFO  TaskSchedulerImpl - Removed TaskSet 751.0, whose tasks have all completed, from pool 
16:01:42.293 INFO  DAGScheduler - ResultStage 751 (runJob at SparkHadoopWriter.scala:83) finished in 0.025 s
16:01:42.293 INFO  DAGScheduler - Job 435 is finished. Cancelling potential speculative or zombie tasks for this job
16:01:42.293 INFO  TaskSchedulerImpl - Killing all running tasks in stage 751: Stage finished
16:01:42.293 INFO  DAGScheduler - Job 435 finished: runJob at SparkHadoopWriter.scala:83, took 0.033837 s
16:01:42.293 INFO  SparkHadoopWriter - Start to commit write Job job_20250519160142968355963334720284_3643.
16:01:42.296 INFO  SparkHadoopWriter - Write Job job_20250519160142968355963334720284_3643 committed. Elapsed time: 3 ms.
16:01:42.304 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local13774000465916765003/markdups2178781706614791083.bam
16:01:42.306 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local13774000465916765003/markdups2178781706614791083.bam done
16:01:42.306 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local13774000465916765003/markdups2178781706614791083.bam.parts/ to /tmp/local13774000465916765003/markdups2178781706614791083.bam.sbi
16:01:42.309 INFO  IndexFileMerger - Done merging .sbi files
16:01:42.309 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local13774000465916765003/markdups2178781706614791083.bam.parts/ to /tmp/local13774000465916765003/markdups2178781706614791083.bam.bai
16:01:42.312 INFO  IndexFileMerger - Done merging .bai files
16:01:42.312 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 4:01:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
16:01:42.329 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:01:42.329 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) va6bd333-SNAPSHOT
16:01:42.329 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
16:01:42.329 INFO  MarkDuplicatesSpark - Executing as root@67ac59543751 on Linux v6.11.0-1014-azure amd64
16:01:42.329 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
16:01:42.330 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 4:01:42 PM GMT
16:01:42.330 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:01:42.330 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:01:42.330 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
16:01:42.330 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
16:01:42.330 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
16:01:42.330 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:01:42.330 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:01:42.330 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:01:42.330 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:01:42.330 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
16:01:42.330 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
16:01:42.330 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
16:01:42.330 INFO  MarkDuplicatesSpark - Requester pays: disabled
16:01:42.330 INFO  MarkDuplicatesSpark - Initializing engine
16:01:42.330 INFO  MarkDuplicatesSpark - Done initializing engine
16:01:42.330 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
16:01:42.332 INFO  MemoryStore - Block broadcast_1425 stored as values in memory (estimated size 305.5 KiB, free 1901.5 MiB)
16:01:42.339 INFO  MemoryStore - Block broadcast_1425_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1901.4 MiB)
16:01:42.339 INFO  BlockManagerInfo - Added broadcast_1425_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1918.5 MiB)
16:01:42.339 INFO  SparkContext - Created broadcast 1425 from newAPIHadoopFile at PathSplitSource.java:96
16:01:42.359 INFO  MemoryStore - Block broadcast_1426 stored as values in memory (estimated size 305.5 KiB, free 1901.1 MiB)
16:01:42.365 INFO  MemoryStore - Block broadcast_1426_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1901.0 MiB)
16:01:42.366 INFO  BlockManagerInfo - Added broadcast_1426_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1918.4 MiB)
16:01:42.366 INFO  SparkContext - Created broadcast 1426 from newAPIHadoopFile at PathSplitSource.java:96
16:01:42.397 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
16:01:42.397 INFO  FileInputFormat - Total input files to process : 1
16:01:42.398 INFO  DAGScheduler - Registering RDD 3657 (mapToPair at SparkUtils.java:161) as input to shuffle 102
16:01:42.398 INFO  DAGScheduler - Got job 436 (collect at SparkUtils.java:205) with 1 output partitions
16:01:42.398 INFO  DAGScheduler - Final stage: ResultStage 753 (collect at SparkUtils.java:205)
16:01:42.398 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 752)
16:01:42.398 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 752)
16:01:42.398 INFO  DAGScheduler - Submitting ShuffleMapStage 752 (MapPartitionsRDD[3657] at mapToPair at SparkUtils.java:161), which has no missing parents
16:01:42.415 INFO  MemoryStore - Block broadcast_1427 stored as values in memory (estimated size 459.2 KiB, free 1900.6 MiB)
16:01:42.417 INFO  MemoryStore - Block broadcast_1427_piece0 stored as bytes in memory (estimated size 201.4 KiB, free 1900.4 MiB)
16:01:42.417 INFO  BlockManagerInfo - Added broadcast_1427_piece0 in memory on localhost:42397 (size: 201.4 KiB, free: 1918.2 MiB)
16:01:42.418 INFO  SparkContext - Created broadcast 1427 from broadcast at DAGScheduler.scala:1580
16:01:42.418 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))
16:01:42.418 INFO  TaskSchedulerImpl - Adding task set 752.0 with 1 tasks resource profile 0
16:01:42.418 INFO  TaskSetManager - Starting task 0.0 in stage 752.0 (TID 678) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9651 bytes) 
16:01:42.418 INFO  Executor - Running task 0.0 in stage 752.0 (TID 678)
16:01:42.447 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/mdOrderBug2.bam:0+1856
16:01:42.451 INFO  Executor - Finished task 0.0 in stage 752.0 (TID 678). 1148 bytes result sent to driver
16:01:42.451 INFO  TaskSetManager - Finished task 0.0 in stage 752.0 (TID 678) in 33 ms on localhost (executor driver) (1/1)
16:01:42.451 INFO  TaskSchedulerImpl - Removed TaskSet 752.0, whose tasks have all completed, from pool 
16:01:42.451 INFO  DAGScheduler - ShuffleMapStage 752 (mapToPair at SparkUtils.java:161) finished in 0.053 s
16:01:42.451 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.451 INFO  DAGScheduler - running: HashSet()
16:01:42.451 INFO  DAGScheduler - waiting: HashSet(ResultStage 753)
16:01:42.451 INFO  DAGScheduler - failed: HashSet()
16:01:42.452 INFO  DAGScheduler - Submitting ResultStage 753 (MapPartitionsRDD[3660] at mapPartitions at SparkUtils.java:188), which has no missing parents
16:01:42.452 INFO  MemoryStore - Block broadcast_1428 stored as values in memory (estimated size 7.4 KiB, free 1900.4 MiB)
16:01:42.453 INFO  MemoryStore - Block broadcast_1428_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1900.4 MiB)
16:01:42.453 INFO  BlockManagerInfo - Added broadcast_1428_piece0 in memory on localhost:42397 (size: 4.1 KiB, free: 1918.2 MiB)
16:01:42.453 INFO  SparkContext - Created broadcast 1428 from broadcast at DAGScheduler.scala:1580
16:01:42.453 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))
16:01:42.453 INFO  TaskSchedulerImpl - Adding task set 753.0 with 1 tasks resource profile 0
16:01:42.454 INFO  TaskSetManager - Starting task 0.0 in stage 753.0 (TID 679) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:01:42.454 INFO  Executor - Running task 0.0 in stage 753.0 (TID 679)
16:01:42.455 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
16:01:42.455 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.457 INFO  Executor - Finished task 0.0 in stage 753.0 (TID 679). 2495 bytes result sent to driver
16:01:42.457 INFO  TaskSetManager - Finished task 0.0 in stage 753.0 (TID 679) in 4 ms on localhost (executor driver) (1/1)
16:01:42.457 INFO  TaskSchedulerImpl - Removed TaskSet 753.0, whose tasks have all completed, from pool 
16:01:42.457 INFO  DAGScheduler - ResultStage 753 (collect at SparkUtils.java:205) finished in 0.005 s
16:01:42.457 INFO  DAGScheduler - Job 436 is finished. Cancelling potential speculative or zombie tasks for this job
16:01:42.457 INFO  TaskSchedulerImpl - Killing all running tasks in stage 753: Stage finished
16:01:42.457 INFO  DAGScheduler - Job 436 finished: collect at SparkUtils.java:205, took 0.060395 s
16:01:42.463 INFO  MemoryStore - Block broadcast_1429 stored as values in memory (estimated size 1632.0 B, free 1900.4 MiB)
16:01:42.463 INFO  MemoryStore - Block broadcast_1429_piece0 stored as bytes in memory (estimated size 145.0 B, free 1900.4 MiB)
16:01:42.463 INFO  BlockManagerInfo - Added broadcast_1429_piece0 in memory on localhost:42397 (size: 145.0 B, free: 1918.2 MiB)
16:01:42.463 INFO  SparkContext - Created broadcast 1429 from broadcast at MarkDuplicatesSparkUtils.java:126
16:01:42.464 INFO  MemoryStore - Block broadcast_1430 stored as values in memory (estimated size 304.0 B, free 1900.4 MiB)
16:01:42.464 INFO  MemoryStore - Block broadcast_1430_piece0 stored as bytes in memory (estimated size 37.0 B, free 1900.4 MiB)
16:01:42.464 INFO  BlockManagerInfo - Added broadcast_1430_piece0 in memory on localhost:42397 (size: 37.0 B, free: 1918.2 MiB)
16:01:42.464 INFO  SparkContext - Created broadcast 1430 from broadcast at MarkDuplicatesSparkUtils.java:127
16:01:42.476 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
16:01:42.476 INFO  DAGScheduler - Registering RDD 3669 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 105
16:01:42.476 INFO  DAGScheduler - Registering RDD 3673 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 104
16:01:42.476 INFO  DAGScheduler - Registering RDD 3677 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 103
16:01:42.477 INFO  DAGScheduler - Got job 437 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
16:01:42.477 INFO  DAGScheduler - Final stage: ResultStage 758 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
16:01:42.477 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 757)
16:01:42.477 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 757)
16:01:42.477 INFO  DAGScheduler - Submitting ShuffleMapStage 755 (MapPartitionsRDD[3669] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
16:01:42.478 INFO  MemoryStore - Block broadcast_1431 stored as values in memory (estimated size 24.2 KiB, free 1900.4 MiB)
16:01:42.478 INFO  MemoryStore - Block broadcast_1431_piece0 stored as bytes in memory (estimated size 12.6 KiB, free 1900.3 MiB)
16:01:42.478 INFO  BlockManagerInfo - Added broadcast_1431_piece0 in memory on localhost:42397 (size: 12.6 KiB, free: 1918.2 MiB)
16:01:42.479 INFO  SparkContext - Created broadcast 1431 from broadcast at DAGScheduler.scala:1580
16:01:42.479 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))
16:01:42.479 INFO  TaskSchedulerImpl - Adding task set 755.0 with 1 tasks resource profile 0
16:01:42.479 INFO  TaskSetManager - Starting task 0.0 in stage 755.0 (TID 680) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
16:01:42.480 INFO  Executor - Running task 0.0 in stage 755.0 (TID 680)
16:01:42.481 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
16:01:42.481 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.484 INFO  Executor - Finished task 0.0 in stage 755.0 (TID 680). 1922 bytes result sent to driver
16:01:42.484 INFO  TaskSetManager - Finished task 0.0 in stage 755.0 (TID 680) in 5 ms on localhost (executor driver) (1/1)
16:01:42.484 INFO  TaskSchedulerImpl - Removed TaskSet 755.0, whose tasks have all completed, from pool 
16:01:42.484 INFO  DAGScheduler - ShuffleMapStage 755 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
16:01:42.484 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.484 INFO  DAGScheduler - running: HashSet()
16:01:42.484 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 756, ShuffleMapStage 757, ResultStage 758)
16:01:42.485 INFO  DAGScheduler - failed: HashSet()
16:01:42.485 INFO  DAGScheduler - Submitting ShuffleMapStage 756 (MapPartitionsRDD[3673] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
16:01:42.485 INFO  MemoryStore - Block broadcast_1432 stored as values in memory (estimated size 28.3 KiB, free 1900.3 MiB)
16:01:42.486 INFO  MemoryStore - Block broadcast_1432_piece0 stored as bytes in memory (estimated size 14.8 KiB, free 1900.3 MiB)
16:01:42.486 INFO  BlockManagerInfo - Added broadcast_1432_piece0 in memory on localhost:42397 (size: 14.8 KiB, free: 1918.2 MiB)
16:01:42.486 INFO  SparkContext - Created broadcast 1432 from broadcast at DAGScheduler.scala:1580
16:01:42.486 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))
16:01:42.486 INFO  TaskSchedulerImpl - Adding task set 756.0 with 1 tasks resource profile 0
16:01:42.487 INFO  TaskSetManager - Starting task 0.0 in stage 756.0 (TID 681) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
16:01:42.487 INFO  Executor - Running task 0.0 in stage 756.0 (TID 681)
16:01:42.488 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
16:01:42.488 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.491 INFO  Executor - Finished task 0.0 in stage 756.0 (TID 681). 1879 bytes result sent to driver
16:01:42.491 INFO  TaskSetManager - Finished task 0.0 in stage 756.0 (TID 681) in 5 ms on localhost (executor driver) (1/1)
16:01:42.491 INFO  TaskSchedulerImpl - Removed TaskSet 756.0, whose tasks have all completed, from pool 
16:01:42.492 INFO  DAGScheduler - ShuffleMapStage 756 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
16:01:42.492 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.492 INFO  DAGScheduler - running: HashSet()
16:01:42.492 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 757, ResultStage 758)
16:01:42.492 INFO  DAGScheduler - failed: HashSet()
16:01:42.492 INFO  DAGScheduler - Submitting ShuffleMapStage 757 (MapPartitionsRDD[3677] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
16:01:42.493 INFO  MemoryStore - Block broadcast_1433 stored as values in memory (estimated size 19.0 KiB, free 1900.3 MiB)
16:01:42.493 INFO  MemoryStore - Block broadcast_1433_piece0 stored as bytes in memory (estimated size 9.7 KiB, free 1900.3 MiB)
16:01:42.493 INFO  BlockManagerInfo - Added broadcast_1433_piece0 in memory on localhost:42397 (size: 9.7 KiB, free: 1918.2 MiB)
16:01:42.493 INFO  SparkContext - Created broadcast 1433 from broadcast at DAGScheduler.scala:1580
16:01:42.493 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))
16:01:42.494 INFO  TaskSchedulerImpl - Adding task set 757.0 with 1 tasks resource profile 0
16:01:42.494 INFO  TaskSetManager - Starting task 0.0 in stage 757.0 (TID 682) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:01:42.494 INFO  Executor - Running task 0.0 in stage 757.0 (TID 682)
16:01:42.496 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
16:01:42.496 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.497 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
16:01:42.497 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.498 INFO  Executor - Finished task 0.0 in stage 757.0 (TID 682). 1879 bytes result sent to driver
16:01:42.499 INFO  TaskSetManager - Finished task 0.0 in stage 757.0 (TID 682) in 5 ms on localhost (executor driver) (1/1)
16:01:42.499 INFO  TaskSchedulerImpl - Removed TaskSet 757.0, whose tasks have all completed, from pool 
16:01:42.499 INFO  DAGScheduler - ShuffleMapStage 757 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.007 s
16:01:42.499 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.499 INFO  DAGScheduler - running: HashSet()
16:01:42.499 INFO  DAGScheduler - waiting: HashSet(ResultStage 758)
16:01:42.499 INFO  DAGScheduler - failed: HashSet()
16:01:42.499 INFO  DAGScheduler - Submitting ResultStage 758 (MapPartitionsRDD[3679] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
16:01:42.500 INFO  MemoryStore - Block broadcast_1434 stored as values in memory (estimated size 20.2 KiB, free 1900.3 MiB)
16:01:42.500 INFO  MemoryStore - Block broadcast_1434_piece0 stored as bytes in memory (estimated size 10.6 KiB, free 1900.2 MiB)
16:01:42.500 INFO  BlockManagerInfo - Added broadcast_1434_piece0 in memory on localhost:42397 (size: 10.6 KiB, free: 1918.1 MiB)
16:01:42.500 INFO  SparkContext - Created broadcast 1434 from broadcast at DAGScheduler.scala:1580
16:01:42.501 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))
16:01:42.501 INFO  TaskSchedulerImpl - Adding task set 758.0 with 1 tasks resource profile 0
16:01:42.501 INFO  TaskSetManager - Starting task 0.0 in stage 758.0 (TID 683) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:01:42.501 INFO  Executor - Running task 0.0 in stage 758.0 (TID 683)
16:01:42.503 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
16:01:42.503 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.505 INFO  Executor - Finished task 0.0 in stage 758.0 (TID 683). 2053 bytes result sent to driver
16:01:42.505 INFO  TaskSetManager - Finished task 0.0 in stage 758.0 (TID 683) in 4 ms on localhost (executor driver) (1/1)
16:01:42.505 INFO  TaskSchedulerImpl - Removed TaskSet 758.0, whose tasks have all completed, from pool 
16:01:42.505 INFO  DAGScheduler - ResultStage 758 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.006 s
16:01:42.506 INFO  DAGScheduler - Job 437 is finished. Cancelling potential speculative or zombie tasks for this job
16:01:42.506 INFO  TaskSchedulerImpl - Killing all running tasks in stage 758: Stage finished
16:01:42.506 INFO  DAGScheduler - Job 437 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.029992 s
16:01:42.516 INFO  MemoryStore - Block broadcast_1435 stored as values in memory (estimated size 20.3 KiB, free 1900.2 MiB)
16:01:42.516 INFO  MemoryStore - Block broadcast_1435_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.2 MiB)
16:01:42.516 INFO  BlockManagerInfo - Added broadcast_1435_piece0 in memory on localhost:42397 (size: 1850.0 B, free: 1918.1 MiB)
16:01:42.517 INFO  SparkContext - Created broadcast 1435 from broadcast at ReadsSparkSink.java:133
16:01:42.517 INFO  MemoryStore - Block broadcast_1436 stored as values in memory (estimated size 20.4 KiB, free 1900.2 MiB)
16:01:42.518 INFO  MemoryStore - Block broadcast_1436_piece0 stored as bytes in memory (estimated size 1850.0 B, free 1900.2 MiB)
16:01:42.518 INFO  BlockManagerInfo - Added broadcast_1436_piece0 in memory on localhost:42397 (size: 1850.0 B, free: 1918.1 MiB)
16:01:42.518 INFO  SparkContext - Created broadcast 1436 from broadcast at BamSink.java:76
16:01:42.519 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
16:01:42.519 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:01:42.519 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:01:42.531 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
16:01:42.531 INFO  DAGScheduler - Registering RDD 3681 (mapToPair at SparkUtils.java:161) as input to shuffle 106
16:01:42.531 INFO  DAGScheduler - Got job 438 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
16:01:42.531 INFO  DAGScheduler - Final stage: ResultStage 763 (runJob at SparkHadoopWriter.scala:83)
16:01:42.532 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 762)
16:01:42.532 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 762)
16:01:42.532 INFO  DAGScheduler - Submitting ShuffleMapStage 762 (MapPartitionsRDD[3681] at mapToPair at SparkUtils.java:161), which has no missing parents
16:01:42.533 INFO  MemoryStore - Block broadcast_1437 stored as values in memory (estimated size 18.1 KiB, free 1900.2 MiB)
16:01:42.533 INFO  MemoryStore - Block broadcast_1437_piece0 stored as bytes in memory (estimated size 9.5 KiB, free 1900.2 MiB)
16:01:42.533 INFO  BlockManagerInfo - Added broadcast_1437_piece0 in memory on localhost:42397 (size: 9.5 KiB, free: 1918.1 MiB)
16:01:42.533 INFO  SparkContext - Created broadcast 1437 from broadcast at DAGScheduler.scala:1580
16:01:42.533 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))
16:01:42.534 INFO  TaskSchedulerImpl - Adding task set 762.0 with 1 tasks resource profile 0
16:01:42.534 INFO  TaskSetManager - Starting task 0.0 in stage 762.0 (TID 684) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:01:42.534 INFO  Executor - Running task 0.0 in stage 762.0 (TID 684)
16:01:42.536 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
16:01:42.536 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.537 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
16:01:42.538 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.539 INFO  Executor - Finished task 0.0 in stage 762.0 (TID 684). 1879 bytes result sent to driver
16:01:42.539 INFO  TaskSetManager - Finished task 0.0 in stage 762.0 (TID 684) in 5 ms on localhost (executor driver) (1/1)
16:01:42.539 INFO  TaskSchedulerImpl - Removed TaskSet 762.0, whose tasks have all completed, from pool 
16:01:42.539 INFO  DAGScheduler - ShuffleMapStage 762 (mapToPair at SparkUtils.java:161) finished in 0.007 s
16:01:42.539 INFO  DAGScheduler - looking for newly runnable stages
16:01:42.539 INFO  DAGScheduler - running: HashSet()
16:01:42.540 INFO  DAGScheduler - waiting: HashSet(ResultStage 763)
16:01:42.540 INFO  DAGScheduler - failed: HashSet()
16:01:42.540 INFO  DAGScheduler - Submitting ResultStage 763 (MapPartitionsRDD[3686] at mapToPair at BamSink.java:91), which has no missing parents
16:01:42.546 INFO  MemoryStore - Block broadcast_1438 stored as values in memory (estimated size 163.3 KiB, free 1900.0 MiB)
16:01:42.547 INFO  MemoryStore - Block broadcast_1438_piece0 stored as bytes in memory (estimated size 73.4 KiB, free 1899.9 MiB)
16:01:42.547 INFO  BlockManagerInfo - Added broadcast_1438_piece0 in memory on localhost:42397 (size: 73.4 KiB, free: 1918.1 MiB)
16:01:42.547 INFO  SparkContext - Created broadcast 1438 from broadcast at DAGScheduler.scala:1580
16:01:42.548 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))
16:01:42.548 INFO  TaskSchedulerImpl - Adding task set 763.0 with 1 tasks resource profile 0
16:01:42.548 INFO  TaskSetManager - Starting task 0.0 in stage 763.0 (TID 685) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:01:42.548 INFO  Executor - Running task 0.0 in stage 763.0 (TID 685)
16:01:42.552 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
16:01:42.552 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:01:42.554 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
16:01:42.554 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:01:42.554 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:01:42.554 INFO  PathOutputCommitterFactory - No output committer factory defined, defaulting to FileOutputCommitterFactory
16:01:42.554 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:01:42.554 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:01:42.565 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191601427956918440701693653_3686_r_000000_0' to file:/tmp/local13774000465916765003/markdups4450785990897483788.bam.parts/_temporary/0/task_202505191601427956918440701693653_3686_r_000000
16:01:42.565 INFO  SparkHadoopMapRedUtil - attempt_202505191601427956918440701693653_3686_r_000000_0: Committed. Elapsed time: 0 ms.
16:01:42.571 INFO  Executor - Finished task 0.0 in stage 763.0 (TID 685). 1944 bytes result sent to driver
16:01:42.571 INFO  BlockManagerInfo - Removed broadcast_1431_piece0 on localhost:42397 in memory (size: 12.6 KiB, free: 1918.1 MiB)
16:01:42.571 INFO  TaskSetManager - Finished task 0.0 in stage 763.0 (TID 685) in 23 ms on localhost (executor driver) (1/1)
16:01:42.571 INFO  TaskSchedulerImpl - Removed TaskSet 763.0, whose tasks have all completed, from pool 
16:01:42.572 INFO  BlockManagerInfo - Removed broadcast_1401_piece0 on localhost:42397 in memory (size: 64.1 KiB, free: 1918.1 MiB)
16:01:42.572 INFO  DAGScheduler - ResultStage 763 (runJob at SparkHadoopWriter.scala:83) finished in 0.032 s
16:01:42.572 INFO  DAGScheduler - Job 438 is finished. Cancelling potential speculative or zombie tasks for this job
16:01:42.572 INFO  TaskSchedulerImpl - Killing all running tasks in stage 763: Stage finished
16:01:42.572 INFO  DAGScheduler - Job 438 finished: runJob at SparkHadoopWriter.scala:83, took 0.040922 s
16:01:42.572 INFO  BlockManagerInfo - Removed broadcast_1437_piece0 on localhost:42397 in memory (size: 9.5 KiB, free: 1918.1 MiB)
16:01:42.572 INFO  SparkHadoopWriter - Start to commit write Job job_202505191601427956918440701693653_3686.
16:01:42.572 INFO  BlockManagerInfo - Removed broadcast_1410_piece0 on localhost:42397 in memory (size: 323.5 KiB, free: 1918.5 MiB)
16:01:42.573 INFO  BlockManagerInfo - Removed broadcast_1420_piece0 on localhost:42397 in memory (size: 10.6 KiB, free: 1918.5 MiB)
16:01:42.573 INFO  BlockManagerInfo - Removed broadcast_1414_piece0 on localhost:42397 in memory (size: 4.1 KiB, free: 1918.5 MiB)
16:01:42.574 INFO  BlockManagerInfo - Removed broadcast_1413_piece0 on localhost:42397 in memory (size: 201.4 KiB, free: 1918.7 MiB)
16:01:42.574 INFO  BlockManagerInfo - Removed broadcast_1411_piece0 on localhost:42397 in memory (size: 64.0 KiB, free: 1918.7 MiB)
16:01:42.575 INFO  BlockManagerInfo - Removed broadcast_1424_piece0 on localhost:42397 in memory (size: 73.4 KiB, free: 1918.8 MiB)
16:01:42.575 INFO  BlockManagerInfo - Removed broadcast_1404_piece0 on localhost:42397 in memory (size: 20.0 B, free: 1918.8 MiB)
16:01:42.575 INFO  BlockManagerInfo - Removed broadcast_1405_piece0 on localhost:42397 in memory (size: 228.2 KiB, free: 1919.0 MiB)
16:01:42.576 INFO  BlockManagerInfo - Removed broadcast_1406_piece0 on localhost:42397 in memory (size: 228.2 KiB, free: 1919.3 MiB)
16:01:42.576 INFO  BlockManagerInfo - Removed broadcast_1422_piece0 on localhost:42397 in memory (size: 1850.0 B, free: 1919.3 MiB)
16:01:42.576 INFO  SparkHadoopWriter - Write Job job_202505191601427956918440701693653_3686 committed. Elapsed time: 4 ms.
16:01:42.576 INFO  BlockManagerInfo - Removed broadcast_1425_piece0 on localhost:42397 in memory (size: 64.0 KiB, free: 1919.3 MiB)
16:01:42.577 INFO  BlockManagerInfo - Removed broadcast_1432_piece0 on localhost:42397 in memory (size: 14.8 KiB, free: 1919.3 MiB)
16:01:42.577 INFO  BlockManagerInfo - Removed broadcast_1433_piece0 on localhost:42397 in memory (size: 9.7 KiB, free: 1919.3 MiB)
16:01:42.578 INFO  BlockManagerInfo - Removed broadcast_1434_piece0 on localhost:42397 in memory (size: 10.6 KiB, free: 1919.4 MiB)
16:01:42.579 INFO  BlockManagerInfo - Removed broadcast_1416_piece0 on localhost:42397 in memory (size: 37.0 B, free: 1919.4 MiB)
16:01:42.579 INFO  BlockManagerInfo - Removed broadcast_1417_piece0 on localhost:42397 in memory (size: 12.6 KiB, free: 1919.4 MiB)
16:01:42.579 INFO  BlockManagerInfo - Removed broadcast_1423_piece0 on localhost:42397 in memory (size: 9.5 KiB, free: 1919.4 MiB)
16:01:42.580 INFO  BlockManagerInfo - Removed broadcast_1412_piece0 on localhost:42397 in memory (size: 64.0 KiB, free: 1919.4 MiB)
16:01:42.580 INFO  BlockManagerInfo - Removed broadcast_1427_piece0 on localhost:42397 in memory (size: 201.4 KiB, free: 1919.6 MiB)
16:01:42.581 INFO  BlockManagerInfo - Removed broadcast_1403_piece0 on localhost:42397 in memory (size: 19.0 B, free: 1919.6 MiB)
16:01:42.581 INFO  BlockManagerInfo - Removed broadcast_1421_piece0 on localhost:42397 in memory (size: 1850.0 B, free: 1919.6 MiB)
16:01:42.582 INFO  BlockManagerInfo - Removed broadcast_1415_piece0 on localhost:42397 in memory (size: 145.0 B, free: 1919.6 MiB)
16:01:42.582 INFO  BlockManagerInfo - Removed broadcast_1428_piece0 on localhost:42397 in memory (size: 4.1 KiB, free: 1919.6 MiB)
16:01:42.583 INFO  BlockManagerInfo - Removed broadcast_1419_piece0 on localhost:42397 in memory (size: 9.7 KiB, free: 1919.6 MiB)
16:01:42.584 INFO  BlockManagerInfo - Removed broadcast_1418_piece0 on localhost:42397 in memory (size: 14.8 KiB, free: 1919.7 MiB)
16:01:42.584 INFO  HadoopFileSystemWrapper - Concatenating 3 parts to /tmp/local13774000465916765003/markdups4450785990897483788.bam
16:01:42.586 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/local13774000465916765003/markdups4450785990897483788.bam done
16:01:42.586 INFO  IndexFileMerger - Merging .sbi files in temp directory /tmp/local13774000465916765003/markdups4450785990897483788.bam.parts/ to /tmp/local13774000465916765003/markdups4450785990897483788.bam.sbi
16:01:42.589 INFO  IndexFileMerger - Done merging .sbi files
16:01:42.589 INFO  IndexFileMerger - Merging .bai files in temp directory /tmp/local13774000465916765003/markdups4450785990897483788.bam.parts/ to /tmp/local13774000465916765003/markdups4450785990897483788.bam.bai
16:01:42.592 INFO  IndexFileMerger - Done merging .bai files
16:01:42.592 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 4:01:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:42 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:43 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:44 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:45 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:47 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:48 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:50 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:51 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:51 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:51 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:52 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:54 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:55 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:56 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:57 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:59 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:59 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:01:59 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:00 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:00 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:00 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:02 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:03 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:03 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:04 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:06 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
16:02:07.112 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.112 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) va6bd333-SNAPSHOT
16:02:07.112 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
16:02:07.112 INFO  MarkDuplicatesSpark - Executing as root@67ac59543751 on Linux v6.11.0-1014-azure amd64
16:02:07.112 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
16:02:07.112 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 4:02:07 PM GMT
16:02:07.112 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.112 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.112 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
16:02:07.113 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
16:02:07.113 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
16:02:07.113 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:02:07.113 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:02:07.113 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:02:07.113 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:02:07.113 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
16:02:07.113 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
16:02:07.113 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
16:02:07.113 INFO  MarkDuplicatesSpark - Requester pays: disabled
16:02:07.113 INFO  MarkDuplicatesSpark - Initializing engine
16:02:07.113 INFO  MarkDuplicatesSpark - Done initializing engine
16:02:07.113 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
16:02:07.115 INFO  MemoryStore - Block broadcast_2015 stored as values in memory (estimated size 305.5 KiB, free 1917.1 MiB)
16:02:07.122 INFO  MemoryStore - Block broadcast_2015_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1917.1 MiB)
16:02:07.122 INFO  BlockManagerInfo - Added broadcast_2015_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1919.3 MiB)
16:02:07.123 INFO  SparkContext - Created broadcast 2015 from newAPIHadoopFile at PathSplitSource.java:96
16:02:07.143 INFO  MemoryStore - Block broadcast_2016 stored as values in memory (estimated size 305.5 KiB, free 1916.8 MiB)
16:02:07.149 INFO  MemoryStore - Block broadcast_2016_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1916.7 MiB)
16:02:07.150 INFO  BlockManagerInfo - Added broadcast_2016_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1919.2 MiB)
16:02:07.150 INFO  SparkContext - Created broadcast 2016 from newAPIHadoopFile at PathSplitSource.java:96
16:02:07.182 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
16:02:07.182 INFO  FileInputFormat - Total input files to process : 1
16:02:07.183 INFO  DAGScheduler - Registering RDD 5578 (mapToPair at SparkUtils.java:161) as input to shuffle 297
16:02:07.183 INFO  DAGScheduler - Got job 569 (collect at SparkUtils.java:205) with 1 output partitions
16:02:07.183 INFO  DAGScheduler - Final stage: ResultStage 1225 (collect at SparkUtils.java:205)
16:02:07.183 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1224)
16:02:07.183 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1224)
16:02:07.183 INFO  DAGScheduler - Submitting ShuffleMapStage 1224 (MapPartitionsRDD[5578] at mapToPair at SparkUtils.java:161), which has no missing parents
16:02:07.200 INFO  MemoryStore - Block broadcast_2017 stored as values in memory (estimated size 492.6 KiB, free 1916.2 MiB)
16:02:07.203 INFO  MemoryStore - Block broadcast_2017_piece0 stored as bytes in memory (estimated size 208.9 KiB, free 1916.0 MiB)
16:02:07.203 INFO  BlockManagerInfo - Added broadcast_2017_piece0 in memory on localhost:42397 (size: 208.9 KiB, free: 1919.0 MiB)
16:02:07.203 INFO  SparkContext - Created broadcast 2017 from broadcast at DAGScheduler.scala:1580
16:02:07.203 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))
16:02:07.204 INFO  TaskSchedulerImpl - Adding task set 1224.0 with 1 tasks resource profile 0
16:02:07.204 INFO  TaskSetManager - Starting task 0.0 in stage 1224.0 (TID 1056) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9674 bytes) 
16:02:07.204 INFO  Executor - Running task 0.0 in stage 1224.0 (TID 1056)
16:02:07.233 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/example.chr1.1-1K.unmarkedDups.bam:0+13412
16:02:07.239 INFO  Executor - Finished task 0.0 in stage 1224.0 (TID 1056). 1148 bytes result sent to driver
16:02:07.239 INFO  TaskSetManager - Finished task 0.0 in stage 1224.0 (TID 1056) in 35 ms on localhost (executor driver) (1/1)
16:02:07.239 INFO  TaskSchedulerImpl - Removed TaskSet 1224.0, whose tasks have all completed, from pool 
16:02:07.239 INFO  DAGScheduler - ShuffleMapStage 1224 (mapToPair at SparkUtils.java:161) finished in 0.056 s
16:02:07.239 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.239 INFO  DAGScheduler - running: HashSet()
16:02:07.239 INFO  DAGScheduler - waiting: HashSet(ResultStage 1225)
16:02:07.239 INFO  DAGScheduler - failed: HashSet()
16:02:07.240 INFO  DAGScheduler - Submitting ResultStage 1225 (MapPartitionsRDD[5581] at mapPartitions at SparkUtils.java:188), which has no missing parents
16:02:07.240 INFO  MemoryStore - Block broadcast_2018 stored as values in memory (estimated size 7.4 KiB, free 1916.0 MiB)
16:02:07.240 INFO  MemoryStore - Block broadcast_2018_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1916.0 MiB)
16:02:07.241 INFO  BlockManagerInfo - Added broadcast_2018_piece0 in memory on localhost:42397 (size: 4.1 KiB, free: 1919.0 MiB)
16:02:07.241 INFO  SparkContext - Created broadcast 2018 from broadcast at DAGScheduler.scala:1580
16:02:07.241 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))
16:02:07.241 INFO  TaskSchedulerImpl - Adding task set 1225.0 with 1 tasks resource profile 0
16:02:07.241 INFO  TaskSetManager - Starting task 0.0 in stage 1225.0 (TID 1057) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.241 INFO  Executor - Running task 0.0 in stage 1225.0 (TID 1057)
16:02:07.242 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
16:02:07.242 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.245 INFO  Executor - Finished task 0.0 in stage 1225.0 (TID 1057). 2329 bytes result sent to driver
16:02:07.245 INFO  TaskSetManager - Finished task 0.0 in stage 1225.0 (TID 1057) in 4 ms on localhost (executor driver) (1/1)
16:02:07.245 INFO  TaskSchedulerImpl - Removed TaskSet 1225.0, whose tasks have all completed, from pool 
16:02:07.245 INFO  DAGScheduler - ResultStage 1225 (collect at SparkUtils.java:205) finished in 0.005 s
16:02:07.245 INFO  DAGScheduler - Job 569 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.245 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1225: Stage finished
16:02:07.245 INFO  DAGScheduler - Job 569 finished: collect at SparkUtils.java:205, took 0.063396 s
16:02:07.249 INFO  MemoryStore - Block broadcast_2019 stored as values in memory (estimated size 7.8 KiB, free 1916.0 MiB)
16:02:07.250 INFO  MemoryStore - Block broadcast_2019_piece0 stored as bytes in memory (estimated size 540.0 B, free 1916.0 MiB)
16:02:07.250 INFO  BlockManagerInfo - Added broadcast_2019_piece0 in memory on localhost:42397 (size: 540.0 B, free: 1919.0 MiB)
16:02:07.250 INFO  SparkContext - Created broadcast 2019 from broadcast at MarkDuplicatesSparkUtils.java:126
16:02:07.250 INFO  MemoryStore - Block broadcast_2020 stored as values in memory (estimated size 2.6 KiB, free 1916.0 MiB)
16:02:07.251 INFO  MemoryStore - Block broadcast_2020_piece0 stored as bytes in memory (estimated size 209.0 B, free 1916.0 MiB)
16:02:07.251 INFO  BlockManagerInfo - Added broadcast_2020_piece0 in memory on localhost:42397 (size: 209.0 B, free: 1919.0 MiB)
16:02:07.251 INFO  SparkContext - Created broadcast 2020 from broadcast at MarkDuplicatesSparkUtils.java:127
16:02:07.265 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
16:02:07.265 INFO  DAGScheduler - Registering RDD 5590 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 300
16:02:07.265 INFO  DAGScheduler - Registering RDD 5594 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 299
16:02:07.266 INFO  DAGScheduler - Registering RDD 5598 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 298
16:02:07.266 INFO  DAGScheduler - Got job 570 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
16:02:07.266 INFO  DAGScheduler - Final stage: ResultStage 1230 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
16:02:07.266 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1229)
16:02:07.266 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1229)
16:02:07.266 INFO  DAGScheduler - Submitting ShuffleMapStage 1227 (MapPartitionsRDD[5590] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
16:02:07.267 INFO  MemoryStore - Block broadcast_2021 stored as values in memory (estimated size 57.6 KiB, free 1916.0 MiB)
16:02:07.267 INFO  MemoryStore - Block broadcast_2021_piece0 stored as bytes in memory (estimated size 19.8 KiB, free 1915.9 MiB)
16:02:07.268 INFO  BlockManagerInfo - Added broadcast_2021_piece0 in memory on localhost:42397 (size: 19.8 KiB, free: 1919.0 MiB)
16:02:07.268 INFO  SparkContext - Created broadcast 2021 from broadcast at DAGScheduler.scala:1580
16:02:07.268 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))
16:02:07.268 INFO  TaskSchedulerImpl - Adding task set 1227.0 with 1 tasks resource profile 0
16:02:07.268 INFO  TaskSetManager - Starting task 0.0 in stage 1227.0 (TID 1058) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
16:02:07.268 INFO  Executor - Running task 0.0 in stage 1227.0 (TID 1058)
16:02:07.270 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
16:02:07.270 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.274 INFO  Executor - Finished task 0.0 in stage 1227.0 (TID 1058). 1922 bytes result sent to driver
16:02:07.274 INFO  TaskSetManager - Finished task 0.0 in stage 1227.0 (TID 1058) in 6 ms on localhost (executor driver) (1/1)
16:02:07.274 INFO  TaskSchedulerImpl - Removed TaskSet 1227.0, whose tasks have all completed, from pool 
16:02:07.274 INFO  DAGScheduler - ShuffleMapStage 1227 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.008 s
16:02:07.274 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.274 INFO  DAGScheduler - running: HashSet()
16:02:07.274 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1228, ShuffleMapStage 1229, ResultStage 1230)
16:02:07.274 INFO  DAGScheduler - failed: HashSet()
16:02:07.275 INFO  DAGScheduler - Submitting ShuffleMapStage 1228 (MapPartitionsRDD[5594] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
16:02:07.276 INFO  MemoryStore - Block broadcast_2022 stored as values in memory (estimated size 61.7 KiB, free 1915.9 MiB)
16:02:07.276 INFO  MemoryStore - Block broadcast_2022_piece0 stored as bytes in memory (estimated size 22.0 KiB, free 1915.9 MiB)
16:02:07.276 INFO  BlockManagerInfo - Added broadcast_2022_piece0 in memory on localhost:42397 (size: 22.0 KiB, free: 1919.0 MiB)
16:02:07.276 INFO  SparkContext - Created broadcast 2022 from broadcast at DAGScheduler.scala:1580
16:02:07.277 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))
16:02:07.277 INFO  TaskSchedulerImpl - Adding task set 1228.0 with 1 tasks resource profile 0
16:02:07.277 INFO  TaskSetManager - Starting task 0.0 in stage 1228.0 (TID 1059) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
16:02:07.277 INFO  Executor - Running task 0.0 in stage 1228.0 (TID 1059)
16:02:07.279 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
16:02:07.279 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.283 INFO  Executor - Finished task 0.0 in stage 1228.0 (TID 1059). 1922 bytes result sent to driver
16:02:07.284 INFO  TaskSetManager - Finished task 0.0 in stage 1228.0 (TID 1059) in 7 ms on localhost (executor driver) (1/1)
16:02:07.284 INFO  TaskSchedulerImpl - Removed TaskSet 1228.0, whose tasks have all completed, from pool 
16:02:07.284 INFO  DAGScheduler - ShuffleMapStage 1228 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.009 s
16:02:07.284 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.284 INFO  DAGScheduler - running: HashSet()
16:02:07.284 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1229, ResultStage 1230)
16:02:07.284 INFO  DAGScheduler - failed: HashSet()
16:02:07.284 INFO  DAGScheduler - Submitting ShuffleMapStage 1229 (MapPartitionsRDD[5598] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
16:02:07.285 INFO  MemoryStore - Block broadcast_2023 stored as values in memory (estimated size 52.4 KiB, free 1915.8 MiB)
16:02:07.285 INFO  MemoryStore - Block broadcast_2023_piece0 stored as bytes in memory (estimated size 17.3 KiB, free 1915.8 MiB)
16:02:07.286 INFO  BlockManagerInfo - Added broadcast_2023_piece0 in memory on localhost:42397 (size: 17.3 KiB, free: 1919.0 MiB)
16:02:07.286 INFO  SparkContext - Created broadcast 2023 from broadcast at DAGScheduler.scala:1580
16:02:07.286 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))
16:02:07.286 INFO  TaskSchedulerImpl - Adding task set 1229.0 with 1 tasks resource profile 0
16:02:07.286 INFO  TaskSetManager - Starting task 0.0 in stage 1229.0 (TID 1060) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:02:07.286 INFO  Executor - Running task 0.0 in stage 1229.0 (TID 1060)
16:02:07.288 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
16:02:07.288 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.290 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
16:02:07.290 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.292 INFO  Executor - Finished task 0.0 in stage 1229.0 (TID 1060). 1922 bytes result sent to driver
16:02:07.292 INFO  TaskSetManager - Finished task 0.0 in stage 1229.0 (TID 1060) in 6 ms on localhost (executor driver) (1/1)
16:02:07.292 INFO  TaskSchedulerImpl - Removed TaskSet 1229.0, whose tasks have all completed, from pool 
16:02:07.292 INFO  DAGScheduler - ShuffleMapStage 1229 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.008 s
16:02:07.292 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.292 INFO  DAGScheduler - running: HashSet()
16:02:07.292 INFO  DAGScheduler - waiting: HashSet(ResultStage 1230)
16:02:07.292 INFO  DAGScheduler - failed: HashSet()
16:02:07.292 INFO  DAGScheduler - Submitting ResultStage 1230 (MapPartitionsRDD[5600] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
16:02:07.293 INFO  MemoryStore - Block broadcast_2024 stored as values in memory (estimated size 53.6 KiB, free 1915.7 MiB)
16:02:07.294 INFO  MemoryStore - Block broadcast_2024_piece0 stored as bytes in memory (estimated size 18.0 KiB, free 1915.7 MiB)
16:02:07.294 INFO  BlockManagerInfo - Added broadcast_2024_piece0 in memory on localhost:42397 (size: 18.0 KiB, free: 1918.9 MiB)
16:02:07.294 INFO  SparkContext - Created broadcast 2024 from broadcast at DAGScheduler.scala:1580
16:02:07.294 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))
16:02:07.294 INFO  TaskSchedulerImpl - Adding task set 1230.0 with 1 tasks resource profile 0
16:02:07.295 INFO  TaskSetManager - Starting task 0.0 in stage 1230.0 (TID 1061) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.295 INFO  Executor - Running task 0.0 in stage 1230.0 (TID 1061)
16:02:07.296 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
16:02:07.296 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.297 INFO  Executor - Finished task 0.0 in stage 1230.0 (TID 1061). 2371 bytes result sent to driver
16:02:07.298 INFO  TaskSetManager - Finished task 0.0 in stage 1230.0 (TID 1061) in 4 ms on localhost (executor driver) (1/1)
16:02:07.298 INFO  TaskSchedulerImpl - Removed TaskSet 1230.0, whose tasks have all completed, from pool 
16:02:07.298 INFO  DAGScheduler - ResultStage 1230 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.005 s
16:02:07.298 INFO  DAGScheduler - Job 570 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.298 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1230: Stage finished
16:02:07.298 INFO  DAGScheduler - Job 570 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.032986 s
16:02:07.311 INFO  MemoryStore - Block broadcast_2025 stored as values in memory (estimated size 179.4 KiB, free 1915.5 MiB)
16:02:07.311 INFO  MemoryStore - Block broadcast_2025_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1915.5 MiB)
16:02:07.311 INFO  BlockManagerInfo - Added broadcast_2025_piece0 in memory on localhost:42397 (size: 7.9 KiB, free: 1918.9 MiB)
16:02:07.312 INFO  SparkContext - Created broadcast 2025 from broadcast at ReadsSparkSink.java:133
16:02:07.315 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
16:02:07.315 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:02:07.315 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:02:07.326 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
16:02:07.326 INFO  DAGScheduler - Registering RDD 5602 (mapToPair at SparkUtils.java:161) as input to shuffle 301
16:02:07.326 INFO  DAGScheduler - Got job 571 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
16:02:07.327 INFO  DAGScheduler - Final stage: ResultStage 1235 (runJob at SparkHadoopWriter.scala:83)
16:02:07.327 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1234)
16:02:07.327 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1234)
16:02:07.327 INFO  DAGScheduler - Submitting ShuffleMapStage 1234 (MapPartitionsRDD[5602] at mapToPair at SparkUtils.java:161), which has no missing parents
16:02:07.328 INFO  MemoryStore - Block broadcast_2026 stored as values in memory (estimated size 51.5 KiB, free 1915.5 MiB)
16:02:07.328 INFO  MemoryStore - Block broadcast_2026_piece0 stored as bytes in memory (estimated size 16.8 KiB, free 1915.5 MiB)
16:02:07.328 INFO  BlockManagerInfo - Added broadcast_2026_piece0 in memory on localhost:42397 (size: 16.8 KiB, free: 1918.9 MiB)
16:02:07.328 INFO  SparkContext - Created broadcast 2026 from broadcast at DAGScheduler.scala:1580
16:02:07.329 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))
16:02:07.329 INFO  TaskSchedulerImpl - Adding task set 1234.0 with 1 tasks resource profile 0
16:02:07.329 INFO  TaskSetManager - Starting task 0.0 in stage 1234.0 (TID 1062) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:02:07.329 INFO  Executor - Running task 0.0 in stage 1234.0 (TID 1062)
16:02:07.331 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
16:02:07.331 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.334 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
16:02:07.334 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.336 INFO  Executor - Finished task 0.0 in stage 1234.0 (TID 1062). 1922 bytes result sent to driver
16:02:07.336 INFO  TaskSetManager - Finished task 0.0 in stage 1234.0 (TID 1062) in 7 ms on localhost (executor driver) (1/1)
16:02:07.336 INFO  TaskSchedulerImpl - Removed TaskSet 1234.0, whose tasks have all completed, from pool 
16:02:07.336 INFO  DAGScheduler - ShuffleMapStage 1234 (mapToPair at SparkUtils.java:161) finished in 0.009 s
16:02:07.336 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.336 INFO  DAGScheduler - running: HashSet()
16:02:07.337 INFO  DAGScheduler - waiting: HashSet(ResultStage 1235)
16:02:07.337 INFO  DAGScheduler - failed: HashSet()
16:02:07.337 INFO  DAGScheduler - Submitting ResultStage 1235 (MapPartitionsRDD[5608] at saveAsTextFile at SamSink.java:65), which has no missing parents
16:02:07.344 INFO  MemoryStore - Block broadcast_2027 stored as values in memory (estimated size 196.3 KiB, free 1915.3 MiB)
16:02:07.345 INFO  MemoryStore - Block broadcast_2027_piece0 stored as bytes in memory (estimated size 80.5 KiB, free 1915.2 MiB)
16:02:07.345 INFO  BlockManagerInfo - Added broadcast_2027_piece0 in memory on localhost:42397 (size: 80.5 KiB, free: 1918.8 MiB)
16:02:07.345 INFO  SparkContext - Created broadcast 2027 from broadcast at DAGScheduler.scala:1580
16:02:07.345 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))
16:02:07.345 INFO  TaskSchedulerImpl - Adding task set 1235.0 with 1 tasks resource profile 0
16:02:07.346 INFO  TaskSetManager - Starting task 0.0 in stage 1235.0 (TID 1063) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.346 INFO  Executor - Running task 0.0 in stage 1235.0 (TID 1063)
16:02:07.349 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
16:02:07.349 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.352 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
16:02:07.352 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:02:07.352 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:02:07.358 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191602073571397478377297836_5608_m_000000_0' to file:/tmp/MarkDups2704444477632446738/MarkDups.sam.parts/_temporary/0/task_202505191602073571397478377297836_5608_m_000000
16:02:07.358 INFO  SparkHadoopMapRedUtil - attempt_202505191602073571397478377297836_5608_m_000000_0: Committed. Elapsed time: 0 ms.
16:02:07.358 INFO  Executor - Finished task 0.0 in stage 1235.0 (TID 1063). 1858 bytes result sent to driver
16:02:07.358 INFO  TaskSetManager - Finished task 0.0 in stage 1235.0 (TID 1063) in 13 ms on localhost (executor driver) (1/1)
16:02:07.358 INFO  TaskSchedulerImpl - Removed TaskSet 1235.0, whose tasks have all completed, from pool 
16:02:07.358 INFO  DAGScheduler - ResultStage 1235 (runJob at SparkHadoopWriter.scala:83) finished in 0.021 s
16:02:07.359 INFO  DAGScheduler - Job 571 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.359 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1235: Stage finished
16:02:07.359 INFO  DAGScheduler - Job 571 finished: runJob at SparkHadoopWriter.scala:83, took 0.032563 s
16:02:07.359 INFO  SparkHadoopWriter - Start to commit write Job job_202505191602073571397478377297836_5608.
16:02:07.361 INFO  SparkHadoopWriter - Write Job job_202505191602073571397478377297836_5608 committed. Elapsed time: 2 ms.
16:02:07.365 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups2704444477632446738/MarkDups.sam
16:02:07.367 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups2704444477632446738/MarkDups.sam done
16:02:07.368 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 4:02:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
16:02:07.383 INFO  BlockManagerInfo - Removed broadcast_2013_piece0 on localhost:42397 in memory (size: 8.0 KiB, free: 1918.9 MiB)
16:02:07.383 INFO  BlockManagerInfo - Removed broadcast_2021_piece0 on localhost:42397 in memory (size: 19.8 KiB, free: 1918.9 MiB)
16:02:07.383 INFO  BlockManagerInfo - Removed broadcast_2025_piece0 on localhost:42397 in memory (size: 7.9 KiB, free: 1918.9 MiB)
16:02:07.384 INFO  BlockManagerInfo - Removed broadcast_2016_piece0 on localhost:42397 in memory (size: 64.0 KiB, free: 1918.9 MiB)
16:02:07.384 INFO  BlockManagerInfo - Removed broadcast_2002_piece0 on localhost:42397 in memory (size: 64.0 KiB, free: 1919.0 MiB)
16:02:07.384 INFO  BlockManagerInfo - Removed broadcast_2024_piece0 on localhost:42397 in memory (size: 18.0 KiB, free: 1919.0 MiB)
16:02:07.385 INFO  BlockManagerInfo - Removed broadcast_2014_piece0 on localhost:42397 in memory (size: 71.6 KiB, free: 1919.1 MiB)
16:02:07.385 INFO  BlockManagerInfo - Removed broadcast_2022_piece0 on localhost:42397 in memory (size: 22.0 KiB, free: 1919.1 MiB)
16:02:07.386 INFO  BlockManagerInfo - Removed broadcast_2019_piece0 on localhost:42397 in memory (size: 540.0 B, free: 1919.1 MiB)
16:02:07.386 INFO  BlockManagerInfo - Removed broadcast_2027_piece0 on localhost:42397 in memory (size: 80.5 KiB, free: 1919.2 MiB)
16:02:07.387 INFO  BlockManagerInfo - Removed broadcast_2006_piece0 on localhost:42397 in memory (size: 19.0 B, free: 1919.2 MiB)
16:02:07.388 INFO  BlockManagerInfo - Removed broadcast_2018_piece0 on localhost:42397 in memory (size: 4.1 KiB, free: 1919.2 MiB)
16:02:07.388 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.388 INFO  BlockManagerInfo - Removed broadcast_2023_piece0 on localhost:42397 in memory (size: 17.3 KiB, free: 1919.2 MiB)
16:02:07.388 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) va6bd333-SNAPSHOT
16:02:07.388 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
16:02:07.388 INFO  MarkDuplicatesSpark - Executing as root@67ac59543751 on Linux v6.11.0-1014-azure amd64
16:02:07.388 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
16:02:07.388 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 4:02:07 PM GMT
16:02:07.388 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.388 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.388 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
16:02:07.388 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
16:02:07.388 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
16:02:07.388 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:02:07.388 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:02:07.388 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:02:07.388 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:02:07.388 INFO  BlockManagerInfo - Removed broadcast_2015_piece0 on localhost:42397 in memory (size: 64.0 KiB, free: 1919.3 MiB)
16:02:07.388 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
16:02:07.388 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
16:02:07.388 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
16:02:07.389 INFO  MarkDuplicatesSpark - Requester pays: disabled
16:02:07.389 INFO  MarkDuplicatesSpark - Initializing engine
16:02:07.389 INFO  MarkDuplicatesSpark - Done initializing engine
16:02:07.389 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
16:02:07.389 INFO  BlockManagerInfo - Removed broadcast_2012_piece0 on localhost:42397 in memory (size: 663.0 B, free: 1919.3 MiB)
16:02:07.389 INFO  BlockManagerInfo - Removed broadcast_2011_piece0 on localhost:42397 in memory (size: 9.1 KiB, free: 1919.3 MiB)
16:02:07.390 INFO  BlockManagerInfo - Removed broadcast_2009_piece0 on localhost:42397 in memory (size: 13.2 KiB, free: 1919.3 MiB)
16:02:07.390 INFO  BlockManagerInfo - Removed broadcast_2003_piece0 on localhost:42397 in memory (size: 64.0 KiB, free: 1919.4 MiB)
16:02:07.390 INFO  BlockManagerInfo - Removed broadcast_2026_piece0 on localhost:42397 in memory (size: 16.8 KiB, free: 1919.4 MiB)
16:02:07.391 INFO  BlockManagerInfo - Removed broadcast_2007_piece0 on localhost:42397 in memory (size: 31.0 B, free: 1919.4 MiB)
16:02:07.391 INFO  MemoryStore - Block broadcast_2028 stored as values in memory (estimated size 305.5 KiB, free 1917.5 MiB)
16:02:07.391 INFO  BlockManagerInfo - Removed broadcast_2008_piece0 on localhost:42397 in memory (size: 11.2 KiB, free: 1919.4 MiB)
16:02:07.391 INFO  BlockManagerInfo - Removed broadcast_2010_piece0 on localhost:42397 in memory (size: 8.5 KiB, free: 1919.4 MiB)
16:02:07.392 INFO  BlockManagerInfo - Removed broadcast_2017_piece0 on localhost:42397 in memory (size: 208.9 KiB, free: 1919.6 MiB)
16:02:07.393 INFO  BlockManagerInfo - Removed broadcast_2004_piece0 on localhost:42397 in memory (size: 200.3 KiB, free: 1919.8 MiB)
16:02:07.393 INFO  BlockManagerInfo - Removed broadcast_2020_piece0 on localhost:42397 in memory (size: 209.0 B, free: 1919.8 MiB)
16:02:07.394 INFO  BlockManagerInfo - Removed broadcast_2005_piece0 on localhost:42397 in memory (size: 4.1 KiB, free: 1919.8 MiB)
16:02:07.399 INFO  MemoryStore - Block broadcast_2028_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1918.8 MiB)
16:02:07.399 INFO  BlockManagerInfo - Added broadcast_2028_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1919.7 MiB)
16:02:07.399 INFO  SparkContext - Created broadcast 2028 from newAPIHadoopFile at PathSplitSource.java:96
16:02:07.419 INFO  MemoryStore - Block broadcast_2029 stored as values in memory (estimated size 305.5 KiB, free 1918.5 MiB)
16:02:07.426 INFO  MemoryStore - Block broadcast_2029_piece0 stored as bytes in memory (estimated size 64.0 KiB, free 1918.5 MiB)
16:02:07.426 INFO  BlockManagerInfo - Added broadcast_2029_piece0 in memory on localhost:42397 (size: 64.0 KiB, free: 1919.7 MiB)
16:02:07.426 INFO  SparkContext - Created broadcast 2029 from newAPIHadoopFile at PathSplitSource.java:96
16:02:07.458 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
16:02:07.459 INFO  FileInputFormat - Total input files to process : 1
16:02:07.459 INFO  DAGScheduler - Registering RDD 5622 (mapToPair at SparkUtils.java:161) as input to shuffle 302
16:02:07.459 INFO  DAGScheduler - Got job 572 (collect at SparkUtils.java:205) with 1 output partitions
16:02:07.459 INFO  DAGScheduler - Final stage: ResultStage 1237 (collect at SparkUtils.java:205)
16:02:07.459 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1236)
16:02:07.459 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1236)
16:02:07.459 INFO  DAGScheduler - Submitting ShuffleMapStage 1236 (MapPartitionsRDD[5622] at mapToPair at SparkUtils.java:161), which has no missing parents
16:02:07.476 INFO  MemoryStore - Block broadcast_2030 stored as values in memory (estimated size 456.1 KiB, free 1918.0 MiB)
16:02:07.478 INFO  MemoryStore - Block broadcast_2030_piece0 stored as bytes in memory (estimated size 200.0 KiB, free 1917.8 MiB)
16:02:07.479 INFO  BlockManagerInfo - Added broadcast_2030_piece0 in memory on localhost:42397 (size: 200.0 KiB, free: 1919.5 MiB)
16:02:07.479 INFO  SparkContext - Created broadcast 2030 from broadcast at DAGScheduler.scala:1580
16:02:07.479 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))
16:02:07.479 INFO  TaskSchedulerImpl - Adding task set 1236.0 with 1 tasks resource profile 0
16:02:07.479 INFO  TaskSetManager - Starting task 0.0 in stage 1236.0 (TID 1064) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9653 bytes) 
16:02:07.480 INFO  Executor - Running task 0.0 in stage 1236.0 (TID 1064)
16:02:07.508 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/optical_dupes.bam:0+678
16:02:07.512 INFO  Executor - Finished task 0.0 in stage 1236.0 (TID 1064). 1148 bytes result sent to driver
16:02:07.512 INFO  TaskSetManager - Finished task 0.0 in stage 1236.0 (TID 1064) in 33 ms on localhost (executor driver) (1/1)
16:02:07.512 INFO  TaskSchedulerImpl - Removed TaskSet 1236.0, whose tasks have all completed, from pool 
16:02:07.512 INFO  DAGScheduler - ShuffleMapStage 1236 (mapToPair at SparkUtils.java:161) finished in 0.053 s
16:02:07.512 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.512 INFO  DAGScheduler - running: HashSet()
16:02:07.512 INFO  DAGScheduler - waiting: HashSet(ResultStage 1237)
16:02:07.512 INFO  DAGScheduler - failed: HashSet()
16:02:07.513 INFO  DAGScheduler - Submitting ResultStage 1237 (MapPartitionsRDD[5625] at mapPartitions at SparkUtils.java:188), which has no missing parents
16:02:07.513 INFO  MemoryStore - Block broadcast_2031 stored as values in memory (estimated size 7.4 KiB, free 1917.8 MiB)
16:02:07.513 INFO  MemoryStore - Block broadcast_2031_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1917.8 MiB)
16:02:07.513 INFO  BlockManagerInfo - Added broadcast_2031_piece0 in memory on localhost:42397 (size: 4.1 KiB, free: 1919.5 MiB)
16:02:07.514 INFO  SparkContext - Created broadcast 2031 from broadcast at DAGScheduler.scala:1580
16:02:07.514 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))
16:02:07.514 INFO  TaskSchedulerImpl - Adding task set 1237.0 with 1 tasks resource profile 0
16:02:07.514 INFO  TaskSetManager - Starting task 0.0 in stage 1237.0 (TID 1065) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.514 INFO  Executor - Running task 0.0 in stage 1237.0 (TID 1065)
16:02:07.515 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
16:02:07.515 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.516 INFO  Executor - Finished task 0.0 in stage 1237.0 (TID 1065). 2269 bytes result sent to driver
16:02:07.517 INFO  TaskSetManager - Finished task 0.0 in stage 1237.0 (TID 1065) in 3 ms on localhost (executor driver) (1/1)
16:02:07.517 INFO  TaskSchedulerImpl - Removed TaskSet 1237.0, whose tasks have all completed, from pool 
16:02:07.517 INFO  DAGScheduler - ResultStage 1237 (collect at SparkUtils.java:205) finished in 0.004 s
16:02:07.517 INFO  DAGScheduler - Job 572 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.517 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1237: Stage finished
16:02:07.517 INFO  DAGScheduler - Job 572 finished: collect at SparkUtils.java:205, took 0.058656 s
16:02:07.521 INFO  MemoryStore - Block broadcast_2032 stored as values in memory (estimated size 136.0 B, free 1917.8 MiB)
16:02:07.521 INFO  MemoryStore - Block broadcast_2032_piece0 stored as bytes in memory (estimated size 24.0 B, free 1917.8 MiB)
16:02:07.521 INFO  BlockManagerInfo - Added broadcast_2032_piece0 in memory on localhost:42397 (size: 24.0 B, free: 1919.5 MiB)
16:02:07.522 INFO  SparkContext - Created broadcast 2032 from broadcast at MarkDuplicatesSparkUtils.java:126
16:02:07.522 INFO  MemoryStore - Block broadcast_2033 stored as values in memory (estimated size 136.0 B, free 1917.8 MiB)
16:02:07.522 INFO  MemoryStore - Block broadcast_2033_piece0 stored as bytes in memory (estimated size 21.0 B, free 1917.8 MiB)
16:02:07.522 INFO  BlockManagerInfo - Added broadcast_2033_piece0 in memory on localhost:42397 (size: 21.0 B, free: 1919.5 MiB)
16:02:07.523 INFO  SparkContext - Created broadcast 2033 from broadcast at MarkDuplicatesSparkUtils.java:127
16:02:07.536 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
16:02:07.536 INFO  DAGScheduler - Registering RDD 5634 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 305
16:02:07.536 INFO  DAGScheduler - Registering RDD 5638 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 304
16:02:07.537 INFO  DAGScheduler - Registering RDD 5642 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 303
16:02:07.537 INFO  DAGScheduler - Got job 573 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
16:02:07.537 INFO  DAGScheduler - Final stage: ResultStage 1242 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
16:02:07.537 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1241)
16:02:07.537 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1241)
16:02:07.537 INFO  DAGScheduler - Submitting ShuffleMapStage 1239 (MapPartitionsRDD[5634] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
16:02:07.537 INFO  MemoryStore - Block broadcast_2034 stored as values in memory (estimated size 21.1 KiB, free 1917.8 MiB)
16:02:07.538 INFO  MemoryStore - Block broadcast_2034_piece0 stored as bytes in memory (estimated size 10.9 KiB, free 1917.8 MiB)
16:02:07.538 INFO  BlockManagerInfo - Added broadcast_2034_piece0 in memory on localhost:42397 (size: 10.9 KiB, free: 1919.5 MiB)
16:02:07.538 INFO  SparkContext - Created broadcast 2034 from broadcast at DAGScheduler.scala:1580
16:02:07.538 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))
16:02:07.538 INFO  TaskSchedulerImpl - Adding task set 1239.0 with 1 tasks resource profile 0
16:02:07.539 INFO  TaskSetManager - Starting task 0.0 in stage 1239.0 (TID 1066) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
16:02:07.539 INFO  Executor - Running task 0.0 in stage 1239.0 (TID 1066)
16:02:07.540 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
16:02:07.540 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.542 INFO  Executor - Finished task 0.0 in stage 1239.0 (TID 1066). 1879 bytes result sent to driver
16:02:07.543 INFO  TaskSetManager - Finished task 0.0 in stage 1239.0 (TID 1066) in 4 ms on localhost (executor driver) (1/1)
16:02:07.543 INFO  TaskSchedulerImpl - Removed TaskSet 1239.0, whose tasks have all completed, from pool 
16:02:07.543 INFO  DAGScheduler - ShuffleMapStage 1239 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.006 s
16:02:07.543 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.543 INFO  DAGScheduler - running: HashSet()
16:02:07.543 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1240, ShuffleMapStage 1241, ResultStage 1242)
16:02:07.543 INFO  DAGScheduler - failed: HashSet()
16:02:07.543 INFO  DAGScheduler - Submitting ShuffleMapStage 1240 (MapPartitionsRDD[5638] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
16:02:07.543 INFO  MemoryStore - Block broadcast_2035 stored as values in memory (estimated size 25.2 KiB, free 1917.8 MiB)
16:02:07.544 INFO  MemoryStore - Block broadcast_2035_piece0 stored as bytes in memory (estimated size 13.1 KiB, free 1917.8 MiB)
16:02:07.544 INFO  BlockManagerInfo - Added broadcast_2035_piece0 in memory on localhost:42397 (size: 13.1 KiB, free: 1919.5 MiB)
16:02:07.544 INFO  SparkContext - Created broadcast 2035 from broadcast at DAGScheduler.scala:1580
16:02:07.544 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))
16:02:07.544 INFO  TaskSchedulerImpl - Adding task set 1240.0 with 1 tasks resource profile 0
16:02:07.545 INFO  TaskSetManager - Starting task 0.0 in stage 1240.0 (TID 1067) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
16:02:07.545 INFO  Executor - Running task 0.0 in stage 1240.0 (TID 1067)
16:02:07.546 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
16:02:07.546 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.549 INFO  Executor - Finished task 0.0 in stage 1240.0 (TID 1067). 1879 bytes result sent to driver
16:02:07.549 INFO  TaskSetManager - Finished task 0.0 in stage 1240.0 (TID 1067) in 4 ms on localhost (executor driver) (1/1)
16:02:07.549 INFO  TaskSchedulerImpl - Removed TaskSet 1240.0, whose tasks have all completed, from pool 
16:02:07.549 INFO  DAGScheduler - ShuffleMapStage 1240 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.006 s
16:02:07.549 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.549 INFO  DAGScheduler - running: HashSet()
16:02:07.549 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1241, ResultStage 1242)
16:02:07.549 INFO  DAGScheduler - failed: HashSet()
16:02:07.549 INFO  DAGScheduler - Submitting ShuffleMapStage 1241 (MapPartitionsRDD[5642] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
16:02:07.550 INFO  MemoryStore - Block broadcast_2036 stored as values in memory (estimated size 15.9 KiB, free 1917.7 MiB)
16:02:07.550 INFO  MemoryStore - Block broadcast_2036_piece0 stored as bytes in memory (estimated size 8.3 KiB, free 1917.7 MiB)
16:02:07.550 INFO  BlockManagerInfo - Added broadcast_2036_piece0 in memory on localhost:42397 (size: 8.3 KiB, free: 1919.4 MiB)
16:02:07.550 INFO  SparkContext - Created broadcast 2036 from broadcast at DAGScheduler.scala:1580
16:02:07.550 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))
16:02:07.550 INFO  TaskSchedulerImpl - Adding task set 1241.0 with 1 tasks resource profile 0
16:02:07.551 INFO  TaskSetManager - Starting task 0.0 in stage 1241.0 (TID 1068) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:02:07.551 INFO  Executor - Running task 0.0 in stage 1241.0 (TID 1068)
16:02:07.552 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
16:02:07.552 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.553 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
16:02:07.553 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.554 INFO  Executor - Finished task 0.0 in stage 1241.0 (TID 1068). 1879 bytes result sent to driver
16:02:07.554 INFO  TaskSetManager - Finished task 0.0 in stage 1241.0 (TID 1068) in 3 ms on localhost (executor driver) (1/1)
16:02:07.554 INFO  TaskSchedulerImpl - Removed TaskSet 1241.0, whose tasks have all completed, from pool 
16:02:07.554 INFO  DAGScheduler - ShuffleMapStage 1241 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.005 s
16:02:07.554 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.554 INFO  DAGScheduler - running: HashSet()
16:02:07.554 INFO  DAGScheduler - waiting: HashSet(ResultStage 1242)
16:02:07.554 INFO  DAGScheduler - failed: HashSet()
16:02:07.554 INFO  DAGScheduler - Submitting ResultStage 1242 (MapPartitionsRDD[5644] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
16:02:07.555 INFO  MemoryStore - Block broadcast_2037 stored as values in memory (estimated size 17.1 KiB, free 1917.7 MiB)
16:02:07.555 INFO  MemoryStore - Block broadcast_2037_piece0 stored as bytes in memory (estimated size 9.0 KiB, free 1917.7 MiB)
16:02:07.555 INFO  BlockManagerInfo - Added broadcast_2037_piece0 in memory on localhost:42397 (size: 9.0 KiB, free: 1919.4 MiB)
16:02:07.555 INFO  SparkContext - Created broadcast 2037 from broadcast at DAGScheduler.scala:1580
16:02:07.556 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))
16:02:07.556 INFO  TaskSchedulerImpl - Adding task set 1242.0 with 1 tasks resource profile 0
16:02:07.556 INFO  TaskSetManager - Starting task 0.0 in stage 1242.0 (TID 1069) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.556 INFO  Executor - Running task 0.0 in stage 1242.0 (TID 1069)
16:02:07.557 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
16:02:07.557 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.558 INFO  Executor - Finished task 0.0 in stage 1242.0 (TID 1069). 1887 bytes result sent to driver
16:02:07.558 INFO  TaskSetManager - Finished task 0.0 in stage 1242.0 (TID 1069) in 2 ms on localhost (executor driver) (1/1)
16:02:07.558 INFO  TaskSchedulerImpl - Removed TaskSet 1242.0, whose tasks have all completed, from pool 
16:02:07.558 INFO  DAGScheduler - ResultStage 1242 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.003 s
16:02:07.558 INFO  DAGScheduler - Job 573 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.559 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1242: Stage finished
16:02:07.559 INFO  DAGScheduler - Job 573 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.022600 s
16:02:07.568 INFO  MemoryStore - Block broadcast_2038 stored as values in memory (estimated size 5.6 KiB, free 1917.7 MiB)
16:02:07.569 INFO  MemoryStore - Block broadcast_2038_piece0 stored as bytes in memory (estimated size 500.0 B, free 1917.7 MiB)
16:02:07.569 INFO  BlockManagerInfo - Added broadcast_2038_piece0 in memory on localhost:42397 (size: 500.0 B, free: 1919.4 MiB)
16:02:07.569 INFO  SparkContext - Created broadcast 2038 from broadcast at ReadsSparkSink.java:133
16:02:07.572 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
16:02:07.572 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:02:07.572 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:02:07.584 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
16:02:07.584 INFO  DAGScheduler - Registering RDD 5646 (mapToPair at SparkUtils.java:161) as input to shuffle 306
16:02:07.584 INFO  DAGScheduler - Got job 574 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
16:02:07.584 INFO  DAGScheduler - Final stage: ResultStage 1247 (runJob at SparkHadoopWriter.scala:83)
16:02:07.584 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1246)
16:02:07.584 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1246)
16:02:07.584 INFO  DAGScheduler - Submitting ShuffleMapStage 1246 (MapPartitionsRDD[5646] at mapToPair at SparkUtils.java:161), which has no missing parents
16:02:07.585 INFO  MemoryStore - Block broadcast_2039 stored as values in memory (estimated size 15.0 KiB, free 1917.7 MiB)
16:02:07.585 INFO  MemoryStore - Block broadcast_2039_piece0 stored as bytes in memory (estimated size 7.9 KiB, free 1917.7 MiB)
16:02:07.585 INFO  BlockManagerInfo - Added broadcast_2039_piece0 in memory on localhost:42397 (size: 7.9 KiB, free: 1919.4 MiB)
16:02:07.585 INFO  SparkContext - Created broadcast 2039 from broadcast at DAGScheduler.scala:1580
16:02:07.586 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))
16:02:07.586 INFO  TaskSchedulerImpl - Adding task set 1246.0 with 1 tasks resource profile 0
16:02:07.586 INFO  TaskSetManager - Starting task 0.0 in stage 1246.0 (TID 1070) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:02:07.586 INFO  Executor - Running task 0.0 in stage 1246.0 (TID 1070)
16:02:07.587 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
16:02:07.587 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.589 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
16:02:07.589 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.590 INFO  Executor - Finished task 0.0 in stage 1246.0 (TID 1070). 1879 bytes result sent to driver
16:02:07.590 INFO  TaskSetManager - Finished task 0.0 in stage 1246.0 (TID 1070) in 4 ms on localhost (executor driver) (1/1)
16:02:07.590 INFO  TaskSchedulerImpl - Removed TaskSet 1246.0, whose tasks have all completed, from pool 
16:02:07.590 INFO  DAGScheduler - ShuffleMapStage 1246 (mapToPair at SparkUtils.java:161) finished in 0.006 s
16:02:07.590 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.590 INFO  DAGScheduler - running: HashSet()
16:02:07.590 INFO  DAGScheduler - waiting: HashSet(ResultStage 1247)
16:02:07.590 INFO  DAGScheduler - failed: HashSet()
16:02:07.590 INFO  DAGScheduler - Submitting ResultStage 1247 (MapPartitionsRDD[5652] at saveAsTextFile at SamSink.java:65), which has no missing parents
16:02:07.597 INFO  MemoryStore - Block broadcast_2040 stored as values in memory (estimated size 159.8 KiB, free 1917.5 MiB)
16:02:07.598 INFO  MemoryStore - Block broadcast_2040_piece0 stored as bytes in memory (estimated size 71.5 KiB, free 1917.5 MiB)
16:02:07.598 INFO  BlockManagerInfo - Added broadcast_2040_piece0 in memory on localhost:42397 (size: 71.5 KiB, free: 1919.4 MiB)
16:02:07.598 INFO  SparkContext - Created broadcast 2040 from broadcast at DAGScheduler.scala:1580
16:02:07.599 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))
16:02:07.599 INFO  TaskSchedulerImpl - Adding task set 1247.0 with 1 tasks resource profile 0
16:02:07.599 INFO  TaskSetManager - Starting task 0.0 in stage 1247.0 (TID 1071) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.599 INFO  Executor - Running task 0.0 in stage 1247.0 (TID 1071)
16:02:07.602 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
16:02:07.602 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.604 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
16:02:07.604 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:02:07.604 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:02:07.610 INFO  FileOutputCommitter - Saved output of task 'attempt_20250519160207289338380496033331_5652_m_000000_0' to file:/tmp/MarkDups10436947302969018299/MarkDups.sam.parts/_temporary/0/task_20250519160207289338380496033331_5652_m_000000
16:02:07.610 INFO  SparkHadoopMapRedUtil - attempt_20250519160207289338380496033331_5652_m_000000_0: Committed. Elapsed time: 0 ms.
16:02:07.610 INFO  Executor - Finished task 0.0 in stage 1247.0 (TID 1071). 1858 bytes result sent to driver
16:02:07.610 INFO  TaskSetManager - Finished task 0.0 in stage 1247.0 (TID 1071) in 11 ms on localhost (executor driver) (1/1)
16:02:07.610 INFO  TaskSchedulerImpl - Removed TaskSet 1247.0, whose tasks have all completed, from pool 
16:02:07.610 INFO  DAGScheduler - ResultStage 1247 (runJob at SparkHadoopWriter.scala:83) finished in 0.020 s
16:02:07.610 INFO  DAGScheduler - Job 574 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.610 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1247: Stage finished
16:02:07.610 INFO  DAGScheduler - Job 574 finished: runJob at SparkHadoopWriter.scala:83, took 0.026606 s
16:02:07.610 INFO  SparkHadoopWriter - Start to commit write Job job_20250519160207289338380496033331_5652.
16:02:07.613 INFO  SparkHadoopWriter - Write Job job_20250519160207289338380496033331_5652 committed. Elapsed time: 2 ms.
16:02:07.616 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups10436947302969018299/MarkDups.sam
16:02:07.618 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups10436947302969018299/MarkDups.sam done
16:02:07.619 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 4:02:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
16:02:07.634 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.634 INFO  MarkDuplicatesSpark - The Genome Analysis Toolkit (GATK) va6bd333-SNAPSHOT
16:02:07.634 INFO  MarkDuplicatesSpark - For support and documentation go to https://software.broadinstitute.org/gatk/
16:02:07.634 INFO  MarkDuplicatesSpark - Executing as root@67ac59543751 on Linux v6.11.0-1014-azure amd64
16:02:07.634 INFO  MarkDuplicatesSpark - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
16:02:07.634 INFO  MarkDuplicatesSpark - Start Date/Time: May 19, 2025 at 4:02:07 PM GMT
16:02:07.634 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.634 INFO  MarkDuplicatesSpark - ------------------------------------------------------------
16:02:07.634 INFO  MarkDuplicatesSpark - HTSJDK Version: test_cram_wiring-SNAPSHOT
16:02:07.634 INFO  MarkDuplicatesSpark - Picard Version: 3.4.0
16:02:07.634 INFO  MarkDuplicatesSpark - Built for Spark Version: 3.5.0
16:02:07.634 INFO  MarkDuplicatesSpark - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:02:07.634 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:02:07.634 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:02:07.634 INFO  MarkDuplicatesSpark - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:02:07.634 INFO  MarkDuplicatesSpark - Deflater: IntelDeflater
16:02:07.634 INFO  MarkDuplicatesSpark - Inflater: IntelInflater
16:02:07.634 INFO  MarkDuplicatesSpark - GCS max retries/reopens: 20
16:02:07.634 INFO  MarkDuplicatesSpark - Requester pays: disabled
16:02:07.634 INFO  MarkDuplicatesSpark - Initializing engine
16:02:07.634 INFO  MarkDuplicatesSpark - Done initializing engine
16:02:07.634 INFO  MarkDuplicatesSpark - Spark verbosity set to INFO (see --spark-verbosity argument)
16:02:07.636 INFO  MemoryStore - Block broadcast_2041 stored as values in memory (estimated size 305.5 KiB, free 1917.2 MiB)
16:02:07.643 INFO  MemoryStore - Block broadcast_2041_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1917.1 MiB)
16:02:07.643 INFO  BlockManagerInfo - Added broadcast_2041_piece0 in memory on localhost:42397 (size: 64.1 KiB, free: 1919.3 MiB)
16:02:07.643 INFO  SparkContext - Created broadcast 2041 from newAPIHadoopFile at PathSplitSource.java:96
16:02:07.663 INFO  MemoryStore - Block broadcast_2042 stored as values in memory (estimated size 305.5 KiB, free 1916.8 MiB)
16:02:07.669 INFO  MemoryStore - Block broadcast_2042_piece0 stored as bytes in memory (estimated size 64.1 KiB, free 1916.7 MiB)
16:02:07.669 INFO  BlockManagerInfo - Added broadcast_2042_piece0 in memory on localhost:42397 (size: 64.1 KiB, free: 1919.2 MiB)
16:02:07.669 INFO  SparkContext - Created broadcast 2042 from newAPIHadoopFile at PathSplitSource.java:96
16:02:07.701 INFO  SparkContext - Starting job: collect at SparkUtils.java:205
16:02:07.701 INFO  FileInputFormat - Total input files to process : 1
16:02:07.702 INFO  DAGScheduler - Registering RDD 5666 (mapToPair at SparkUtils.java:161) as input to shuffle 307
16:02:07.702 INFO  DAGScheduler - Got job 575 (collect at SparkUtils.java:205) with 1 output partitions
16:02:07.702 INFO  DAGScheduler - Final stage: ResultStage 1249 (collect at SparkUtils.java:205)
16:02:07.702 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1248)
16:02:07.702 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1248)
16:02:07.702 INFO  DAGScheduler - Submitting ShuffleMapStage 1248 (MapPartitionsRDD[5666] at mapToPair at SparkUtils.java:161), which has no missing parents
16:02:07.720 INFO  MemoryStore - Block broadcast_2043 stored as values in memory (estimated size 480.2 KiB, free 1916.3 MiB)
16:02:07.722 INFO  MemoryStore - Block broadcast_2043_piece0 stored as bytes in memory (estimated size 206.2 KiB, free 1916.1 MiB)
16:02:07.722 INFO  BlockManagerInfo - Added broadcast_2043_piece0 in memory on localhost:42397 (size: 206.2 KiB, free: 1919.0 MiB)
16:02:07.722 INFO  SparkContext - Created broadcast 2043 from broadcast at DAGScheduler.scala:1580
16:02:07.722 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))
16:02:07.722 INFO  TaskSchedulerImpl - Adding task set 1248.0 with 1 tasks resource profile 0
16:02:07.723 INFO  TaskSetManager - Starting task 0.0 in stage 1248.0 (TID 1072) (localhost, executor driver, partition 0, PROCESS_LOCAL, 9673 bytes) 
16:02:07.723 INFO  Executor - Running task 0.0 in stage 1248.0 (TID 1072)
16:02:07.751 INFO  NewHadoopRDD - Input split: file:/gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/MarkDuplicatesGATK/inputSingleLibrarySolexa16404.bam:0+5416
16:02:07.756 INFO  Executor - Finished task 0.0 in stage 1248.0 (TID 1072). 1148 bytes result sent to driver
16:02:07.757 INFO  TaskSetManager - Finished task 0.0 in stage 1248.0 (TID 1072) in 34 ms on localhost (executor driver) (1/1)
16:02:07.757 INFO  TaskSchedulerImpl - Removed TaskSet 1248.0, whose tasks have all completed, from pool 
16:02:07.757 INFO  DAGScheduler - ShuffleMapStage 1248 (mapToPair at SparkUtils.java:161) finished in 0.055 s
16:02:07.757 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.757 INFO  DAGScheduler - running: HashSet()
16:02:07.757 INFO  DAGScheduler - waiting: HashSet(ResultStage 1249)
16:02:07.757 INFO  DAGScheduler - failed: HashSet()
16:02:07.757 INFO  DAGScheduler - Submitting ResultStage 1249 (MapPartitionsRDD[5669] at mapPartitions at SparkUtils.java:188), which has no missing parents
16:02:07.757 INFO  MemoryStore - Block broadcast_2044 stored as values in memory (estimated size 7.4 KiB, free 1916.1 MiB)
16:02:07.758 INFO  MemoryStore - Block broadcast_2044_piece0 stored as bytes in memory (estimated size 4.1 KiB, free 1916.1 MiB)
16:02:07.758 INFO  BlockManagerInfo - Added broadcast_2044_piece0 in memory on localhost:42397 (size: 4.1 KiB, free: 1919.0 MiB)
16:02:07.758 INFO  SparkContext - Created broadcast 2044 from broadcast at DAGScheduler.scala:1580
16:02:07.758 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))
16:02:07.758 INFO  TaskSchedulerImpl - Adding task set 1249.0 with 1 tasks resource profile 0
16:02:07.759 INFO  TaskSetManager - Starting task 0.0 in stage 1249.0 (TID 1073) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.759 INFO  Executor - Running task 0.0 in stage 1249.0 (TID 1073)
16:02:07.760 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
16:02:07.760 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.761 INFO  Executor - Finished task 0.0 in stage 1249.0 (TID 1073). 2039 bytes result sent to driver
16:02:07.761 INFO  TaskSetManager - Finished task 0.0 in stage 1249.0 (TID 1073) in 2 ms on localhost (executor driver) (1/1)
16:02:07.761 INFO  TaskSchedulerImpl - Removed TaskSet 1249.0, whose tasks have all completed, from pool 
16:02:07.761 INFO  DAGScheduler - ResultStage 1249 (collect at SparkUtils.java:205) finished in 0.004 s
16:02:07.761 INFO  DAGScheduler - Job 575 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.761 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1249: Stage finished
16:02:07.762 INFO  DAGScheduler - Job 575 finished: collect at SparkUtils.java:205, took 0.060667 s
16:02:07.765 INFO  MemoryStore - Block broadcast_2045 stored as values in memory (estimated size 392.0 B, free 1916.1 MiB)
16:02:07.766 INFO  MemoryStore - Block broadcast_2045_piece0 stored as bytes in memory (estimated size 33.0 B, free 1916.1 MiB)
16:02:07.766 INFO  BlockManagerInfo - Added broadcast_2045_piece0 in memory on localhost:42397 (size: 33.0 B, free: 1919.0 MiB)
16:02:07.766 INFO  SparkContext - Created broadcast 2045 from broadcast at MarkDuplicatesSparkUtils.java:126
16:02:07.766 INFO  MemoryStore - Block broadcast_2046 stored as values in memory (estimated size 144.0 B, free 1916.1 MiB)
16:02:07.766 INFO  MemoryStore - Block broadcast_2046_piece0 stored as bytes in memory (estimated size 28.0 B, free 1916.1 MiB)
16:02:07.767 INFO  BlockManagerInfo - Added broadcast_2046_piece0 in memory on localhost:42397 (size: 28.0 B, free: 1919.0 MiB)
16:02:07.767 INFO  SparkContext - Created broadcast 2046 from broadcast at MarkDuplicatesSparkUtils.java:127
16:02:07.779 INFO  SparkContext - Starting job: collectAsMap at MarkDuplicatesSparkUtils.java:542
16:02:07.780 INFO  DAGScheduler - Registering RDD 5678 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) as input to shuffle 310
16:02:07.780 INFO  DAGScheduler - Registering RDD 5682 (mapToPair at MarkDuplicatesSpark.java:217) as input to shuffle 309
16:02:07.780 INFO  DAGScheduler - Registering RDD 5686 (mapToPair at MarkDuplicatesSparkUtils.java:497) as input to shuffle 308
16:02:07.780 INFO  DAGScheduler - Got job 576 (collectAsMap at MarkDuplicatesSparkUtils.java:542) with 1 output partitions
16:02:07.780 INFO  DAGScheduler - Final stage: ResultStage 1254 (collectAsMap at MarkDuplicatesSparkUtils.java:542)
16:02:07.780 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1253)
16:02:07.780 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1253)
16:02:07.780 INFO  DAGScheduler - Submitting ShuffleMapStage 1251 (MapPartitionsRDD[5678] at flatMapToPair at MarkDuplicatesSparkUtils.java:130), which has no missing parents
16:02:07.781 INFO  MemoryStore - Block broadcast_2047 stored as values in memory (estimated size 45.2 KiB, free 1916.0 MiB)
16:02:07.782 INFO  MemoryStore - Block broadcast_2047_piece0 stored as bytes in memory (estimated size 17.1 KiB, free 1916.0 MiB)
16:02:07.782 INFO  BlockManagerInfo - Added broadcast_2047_piece0 in memory on localhost:42397 (size: 17.1 KiB, free: 1919.0 MiB)
16:02:07.782 INFO  SparkContext - Created broadcast 2047 from broadcast at DAGScheduler.scala:1580
16:02:07.782 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))
16:02:07.782 INFO  TaskSchedulerImpl - Adding task set 1251.0 with 1 tasks resource profile 0
16:02:07.783 INFO  TaskSetManager - Starting task 0.0 in stage 1251.0 (TID 1074) (localhost, executor driver, partition 0, NODE_LOCAL, 9813 bytes) 
16:02:07.783 INFO  Executor - Running task 0.0 in stage 1251.0 (TID 1074)
16:02:07.784 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
16:02:07.784 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.787 INFO  Executor - Finished task 0.0 in stage 1251.0 (TID 1074). 1922 bytes result sent to driver
16:02:07.787 INFO  TaskSetManager - Finished task 0.0 in stage 1251.0 (TID 1074) in 5 ms on localhost (executor driver) (1/1)
16:02:07.787 INFO  TaskSchedulerImpl - Removed TaskSet 1251.0, whose tasks have all completed, from pool 
16:02:07.787 INFO  DAGScheduler - ShuffleMapStage 1251 (flatMapToPair at MarkDuplicatesSparkUtils.java:130) finished in 0.007 s
16:02:07.787 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.787 INFO  DAGScheduler - running: HashSet()
16:02:07.787 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1252, ShuffleMapStage 1253, ResultStage 1254)
16:02:07.787 INFO  DAGScheduler - failed: HashSet()
16:02:07.787 INFO  DAGScheduler - Submitting ShuffleMapStage 1252 (MapPartitionsRDD[5682] at mapToPair at MarkDuplicatesSpark.java:217), which has no missing parents
16:02:07.788 INFO  MemoryStore - Block broadcast_2048 stored as values in memory (estimated size 49.3 KiB, free 1915.9 MiB)
16:02:07.789 INFO  MemoryStore - Block broadcast_2048_piece0 stored as bytes in memory (estimated size 19.3 KiB, free 1915.9 MiB)
16:02:07.789 INFO  BlockManagerInfo - Added broadcast_2048_piece0 in memory on localhost:42397 (size: 19.3 KiB, free: 1919.0 MiB)
16:02:07.789 INFO  SparkContext - Created broadcast 2048 from broadcast at DAGScheduler.scala:1580
16:02:07.789 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))
16:02:07.789 INFO  TaskSchedulerImpl - Adding task set 1252.0 with 1 tasks resource profile 0
16:02:07.789 INFO  TaskSetManager - Starting task 0.0 in stage 1252.0 (TID 1075) (localhost, executor driver, partition 0, NODE_LOCAL, 9288 bytes) 
16:02:07.790 INFO  Executor - Running task 0.0 in stage 1252.0 (TID 1075)
16:02:07.791 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
16:02:07.791 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.794 INFO  Executor - Finished task 0.0 in stage 1252.0 (TID 1075). 1922 bytes result sent to driver
16:02:07.795 INFO  TaskSetManager - Finished task 0.0 in stage 1252.0 (TID 1075) in 6 ms on localhost (executor driver) (1/1)
16:02:07.795 INFO  TaskSchedulerImpl - Removed TaskSet 1252.0, whose tasks have all completed, from pool 
16:02:07.795 INFO  DAGScheduler - ShuffleMapStage 1252 (mapToPair at MarkDuplicatesSpark.java:217) finished in 0.007 s
16:02:07.795 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.795 INFO  DAGScheduler - running: HashSet()
16:02:07.795 INFO  DAGScheduler - waiting: HashSet(ShuffleMapStage 1253, ResultStage 1254)
16:02:07.795 INFO  DAGScheduler - failed: HashSet()
16:02:07.795 INFO  DAGScheduler - Submitting ShuffleMapStage 1253 (MapPartitionsRDD[5686] at mapToPair at MarkDuplicatesSparkUtils.java:497), which has no missing parents
16:02:07.796 INFO  MemoryStore - Block broadcast_2049 stored as values in memory (estimated size 40.0 KiB, free 1915.9 MiB)
16:02:07.796 INFO  MemoryStore - Block broadcast_2049_piece0 stored as bytes in memory (estimated size 14.5 KiB, free 1915.9 MiB)
16:02:07.796 INFO  BlockManagerInfo - Added broadcast_2049_piece0 in memory on localhost:42397 (size: 14.5 KiB, free: 1919.0 MiB)
16:02:07.796 INFO  SparkContext - Created broadcast 2049 from broadcast at DAGScheduler.scala:1580
16:02:07.797 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))
16:02:07.797 INFO  TaskSchedulerImpl - Adding task set 1253.0 with 1 tasks resource profile 0
16:02:07.797 INFO  TaskSetManager - Starting task 0.0 in stage 1253.0 (TID 1076) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:02:07.797 INFO  Executor - Running task 0.0 in stage 1253.0 (TID 1076)
16:02:07.798 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
16:02:07.798 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.799 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
16:02:07.800 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.801 INFO  Executor - Finished task 0.0 in stage 1253.0 (TID 1076). 1879 bytes result sent to driver
16:02:07.801 INFO  TaskSetManager - Finished task 0.0 in stage 1253.0 (TID 1076) in 4 ms on localhost (executor driver) (1/1)
16:02:07.801 INFO  TaskSchedulerImpl - Removed TaskSet 1253.0, whose tasks have all completed, from pool 
16:02:07.801 INFO  DAGScheduler - ShuffleMapStage 1253 (mapToPair at MarkDuplicatesSparkUtils.java:497) finished in 0.006 s
16:02:07.801 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.801 INFO  DAGScheduler - running: HashSet()
16:02:07.801 INFO  DAGScheduler - waiting: HashSet(ResultStage 1254)
16:02:07.801 INFO  DAGScheduler - failed: HashSet()
16:02:07.801 INFO  DAGScheduler - Submitting ResultStage 1254 (MapPartitionsRDD[5688] at mapValues at MarkDuplicatesSparkUtils.java:519), which has no missing parents
16:02:07.802 INFO  MemoryStore - Block broadcast_2050 stored as values in memory (estimated size 41.2 KiB, free 1915.8 MiB)
16:02:07.802 INFO  MemoryStore - Block broadcast_2050_piece0 stored as bytes in memory (estimated size 15.3 KiB, free 1915.8 MiB)
16:02:07.802 INFO  BlockManagerInfo - Added broadcast_2050_piece0 in memory on localhost:42397 (size: 15.3 KiB, free: 1919.0 MiB)
16:02:07.803 INFO  SparkContext - Created broadcast 2050 from broadcast at DAGScheduler.scala:1580
16:02:07.803 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))
16:02:07.803 INFO  TaskSchedulerImpl - Adding task set 1254.0 with 1 tasks resource profile 0
16:02:07.803 INFO  TaskSetManager - Starting task 0.0 in stage 1254.0 (TID 1077) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.803 INFO  Executor - Running task 0.0 in stage 1254.0 (TID 1077)
16:02:07.805 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
16:02:07.805 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.806 INFO  Executor - Finished task 0.0 in stage 1254.0 (TID 1077). 1944 bytes result sent to driver
16:02:07.806 INFO  TaskSetManager - Finished task 0.0 in stage 1254.0 (TID 1077) in 3 ms on localhost (executor driver) (1/1)
16:02:07.807 INFO  TaskSchedulerImpl - Removed TaskSet 1254.0, whose tasks have all completed, from pool 
16:02:07.807 INFO  DAGScheduler - ResultStage 1254 (collectAsMap at MarkDuplicatesSparkUtils.java:542) finished in 0.006 s
16:02:07.807 INFO  DAGScheduler - Job 576 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.807 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1254: Stage finished
16:02:07.807 INFO  DAGScheduler - Job 576 finished: collectAsMap at MarkDuplicatesSparkUtils.java:542, took 0.027441 s
16:02:07.818 INFO  MemoryStore - Block broadcast_2051 stored as values in memory (estimated size 93.5 KiB, free 1915.7 MiB)
16:02:07.818 INFO  MemoryStore - Block broadcast_2051_piece0 stored as bytes in memory (estimated size 5.6 KiB, free 1915.7 MiB)
16:02:07.818 INFO  BlockManagerInfo - Added broadcast_2051_piece0 in memory on localhost:42397 (size: 5.6 KiB, free: 1919.0 MiB)
16:02:07.818 INFO  SparkContext - Created broadcast 2051 from broadcast at ReadsSparkSink.java:133
16:02:07.821 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
16:02:07.822 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:02:07.822 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:02:07.833 INFO  SparkContext - Starting job: runJob at SparkHadoopWriter.scala:83
16:02:07.833 INFO  DAGScheduler - Registering RDD 5690 (mapToPair at SparkUtils.java:161) as input to shuffle 311
16:02:07.833 INFO  DAGScheduler - Got job 577 (runJob at SparkHadoopWriter.scala:83) with 1 output partitions
16:02:07.833 INFO  DAGScheduler - Final stage: ResultStage 1259 (runJob at SparkHadoopWriter.scala:83)
16:02:07.833 INFO  DAGScheduler - Parents of final stage: List(ShuffleMapStage 1258)
16:02:07.833 INFO  DAGScheduler - Missing parents: List(ShuffleMapStage 1258)
16:02:07.833 INFO  DAGScheduler - Submitting ShuffleMapStage 1258 (MapPartitionsRDD[5690] at mapToPair at SparkUtils.java:161), which has no missing parents
16:02:07.834 INFO  MemoryStore - Block broadcast_2052 stored as values in memory (estimated size 39.1 KiB, free 1915.7 MiB)
16:02:07.834 INFO  MemoryStore - Block broadcast_2052_piece0 stored as bytes in memory (estimated size 14.1 KiB, free 1915.7 MiB)
16:02:07.834 INFO  BlockManagerInfo - Added broadcast_2052_piece0 in memory on localhost:42397 (size: 14.1 KiB, free: 1918.9 MiB)
16:02:07.835 INFO  SparkContext - Created broadcast 2052 from broadcast at DAGScheduler.scala:1580
16:02:07.835 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))
16:02:07.835 INFO  TaskSchedulerImpl - Adding task set 1258.0 with 1 tasks resource profile 0
16:02:07.835 INFO  TaskSetManager - Starting task 0.0 in stage 1258.0 (TID 1078) (localhost, executor driver, partition 0, NODE_LOCAL, 9871 bytes) 
16:02:07.835 INFO  Executor - Running task 0.0 in stage 1258.0 (TID 1078)
16:02:07.837 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
16:02:07.837 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.838 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
16:02:07.838 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.839 INFO  Executor - Finished task 0.0 in stage 1258.0 (TID 1078). 1922 bytes result sent to driver
16:02:07.840 INFO  TaskSetManager - Finished task 0.0 in stage 1258.0 (TID 1078) in 5 ms on localhost (executor driver) (1/1)
16:02:07.840 INFO  TaskSchedulerImpl - Removed TaskSet 1258.0, whose tasks have all completed, from pool 
16:02:07.840 INFO  DAGScheduler - ShuffleMapStage 1258 (mapToPair at SparkUtils.java:161) finished in 0.007 s
16:02:07.840 INFO  DAGScheduler - looking for newly runnable stages
16:02:07.840 INFO  DAGScheduler - running: HashSet()
16:02:07.840 INFO  DAGScheduler - waiting: HashSet(ResultStage 1259)
16:02:07.840 INFO  DAGScheduler - failed: HashSet()
16:02:07.840 INFO  DAGScheduler - Submitting ResultStage 1259 (MapPartitionsRDD[5696] at saveAsTextFile at SamSink.java:65), which has no missing parents
16:02:07.846 INFO  MemoryStore - Block broadcast_2053 stored as values in memory (estimated size 183.9 KiB, free 1915.5 MiB)
16:02:07.847 INFO  MemoryStore - Block broadcast_2053_piece0 stored as bytes in memory (estimated size 77.7 KiB, free 1915.4 MiB)
16:02:07.847 INFO  BlockManagerInfo - Added broadcast_2053_piece0 in memory on localhost:42397 (size: 77.7 KiB, free: 1918.9 MiB)
16:02:07.848 INFO  SparkContext - Created broadcast 2053 from broadcast at DAGScheduler.scala:1580
16:02:07.848 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))
16:02:07.848 INFO  TaskSchedulerImpl - Adding task set 1259.0 with 1 tasks resource profile 0
16:02:07.848 INFO  TaskSetManager - Starting task 0.0 in stage 1259.0 (TID 1079) (localhost, executor driver, partition 0, NODE_LOCAL, 9299 bytes) 
16:02:07.848 INFO  Executor - Running task 0.0 in stage 1259.0 (TID 1079)
16:02:07.852 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
16:02:07.852 INFO  ShuffleBlockFetcherIterator - Started 0 remote fetches in 0 ms
16:02:07.853 INFO  HadoopMapRedCommitProtocol - Using output committer class org.apache.hadoop.mapred.FileOutputCommitter
16:02:07.853 INFO  FileOutputCommitter - File Output Committer Algorithm version is 1
16:02:07.853 INFO  FileOutputCommitter - FileOutputCommitter skip cleanup _temporary folders under output directory:false, ignore cleanup failures: false
16:02:07.859 INFO  FileOutputCommitter - Saved output of task 'attempt_202505191602075483652289307443919_5696_m_000000_0' to file:/tmp/MarkDups12998395014682154056/MarkDups.sam.parts/_temporary/0/task_202505191602075483652289307443919_5696_m_000000
16:02:07.859 INFO  SparkHadoopMapRedUtil - attempt_202505191602075483652289307443919_5696_m_000000_0: Committed. Elapsed time: 0 ms.
16:02:07.859 INFO  Executor - Finished task 0.0 in stage 1259.0 (TID 1079). 1858 bytes result sent to driver
16:02:07.860 INFO  TaskSetManager - Finished task 0.0 in stage 1259.0 (TID 1079) in 12 ms on localhost (executor driver) (1/1)
16:02:07.860 INFO  TaskSchedulerImpl - Removed TaskSet 1259.0, whose tasks have all completed, from pool 
16:02:07.860 INFO  DAGScheduler - ResultStage 1259 (runJob at SparkHadoopWriter.scala:83) finished in 0.020 s
16:02:07.860 INFO  DAGScheduler - Job 577 is finished. Cancelling potential speculative or zombie tasks for this job
16:02:07.860 INFO  TaskSchedulerImpl - Killing all running tasks in stage 1259: Stage finished
16:02:07.860 INFO  DAGScheduler - Job 577 finished: runJob at SparkHadoopWriter.scala:83, took 0.027415 s
16:02:07.860 INFO  SparkHadoopWriter - Start to commit write Job job_202505191602075483652289307443919_5696.
16:02:07.863 INFO  SparkHadoopWriter - Write Job job_202505191602075483652289307443919_5696 committed. Elapsed time: 2 ms.
16:02:07.867 INFO  HadoopFileSystemWrapper - Concatenating 2 parts to /tmp/MarkDups12998395014682154056/MarkDups.sam
16:02:07.869 INFO  HadoopFileSystemWrapper - Concatenating to /tmp/MarkDups12998395014682154056/MarkDups.sam done
16:02:07.869 INFO  MarkDuplicatesSpark - Shutting down engine
[May 19, 2025 at 4:02:07 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:08 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:09 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:10 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:11 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:12 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
16:02:13.729 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-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-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-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-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) [?:?]
16:02:13.744 ERROR TaskSetManager - Task 0 in stage 1479.0 failed 1 times; aborting job
[May 19, 2025 at 4:02:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
16:02:13.985 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-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.EmptyFragment.<init>(EmptyFragment.java:36) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.broadinstitute.hellbender.utils.read.markduplicates.sparkrecords.MarkDuplicatesSparkRecord.newEmptyFragment(MarkDuplicatesSparkRecord.java:44) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSparkUtils.lambda$transformToDuplicateNames$0(MarkDuplicatesSparkUtils.java:141) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-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-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.api.java.JavaRDDLike.$anonfun$flatMapToPair$1(JavaRDDLike.scala:143) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.nextCur(Iterator.scala:594) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at scala.collection.Iterator$$anon$10.hasNext(Iterator.scala:608) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.shuffle.sort.BypassMergeSortShuffleWriter.write(BypassMergeSortShuffleWriter.java:140) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:104) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:54) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.TaskContext.runTaskWithListeners(TaskContext.scala:161) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.scheduler.Task.run(Task.scala:141) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$4(Executor.scala:620) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally(SparkErrorUtils.scala:64) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.util.SparkErrorUtils.tryWithSafeFinally$(SparkErrorUtils.scala:61) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:94) ~[gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-SNAPSHOT]
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:623) [gatk-package-a6bd333-SNAPSHOT-local.jar:a6bd333-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) [?:?]
16:02:13.987 ERROR TaskSetManager - Task 0 in stage 1486.0 failed 1 times; aborting job
[May 19, 2025 at 4:02:13 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:14 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:15 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:16 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:17 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:18 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:19 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:20 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:21 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:22 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:23 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:24 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:25 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:26 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:27 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:28 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:29 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:30 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:31 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:32 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:33 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:34 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:35 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:36 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:37 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744
[May 19, 2025 at 4:02:38 PM GMT] org.broadinstitute.hellbender.tools.spark.transforms.markduplicates.MarkDuplicatesSpark done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=989855744