Class org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibratorIntegrationTest

all > org.broadinstitute.hellbender.tools.walkers.vqsr > VariantRecalibratorIntegrationTest
17

tests
0

failures
0

ignored
33.579s

duration
100%

successful

Tests

Test Duration Result
testAnnotationsWithNoVarianceSpecified 0.580s passed
testBothAggregateRecalMode 4.846s passed
testBothRecalMode 2.484s passed
testInGatkLiteDocker 0.105s passed
testNoNegativeTrainingData 0.555s passed
testVQSRAnnotationOrder 0.247s passed
testVariantRecalibratorIndel 0.841s passed
testVariantRecalibratorModelInput 1.304s passed
testVariantRecalibratorRScriptOutput 1.615s passed
testVariantRecalibratorSNPAlternateTranches[0]([Ljava.lang.String;@5c316230, /gatkCloneMountPoint/src/test/resources/large/VQSR/expected/SNPAlternateTranches.txt, /gatkCloneMountPoint/src/test/resources/large/VQSR/snpRecal.vcf) 3.042s passed
testVariantRecalibratorSNPAlternateTranches[1]([Ljava.lang.String;@d02c00, /gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/VQSR/expected.AS.alternate.tranches, /gatkCloneMountPoint/src/test/resources/large/VQSR/expected/expected.AS.recal.vcf) 0.415s passed
testVariantRecalibratorSNPMaxAttempts[0]([Ljava.lang.String;@239d9cb7) 5.466s passed
testVariantRecalibratorSNP[0]([Ljava.lang.String;@6bf28f61, /gatkCloneMountPoint/src/test/resources/large/VQSR/expected/SNPDefaultTranches.txt, /gatkCloneMountPoint/src/test/resources/large/VQSR/snpRecal.vcf) 3.836s passed
testVariantRecalibratorSNP[1]([Ljava.lang.String;@5c316230, /gatkCloneMountPoint/src/test/resources/large/VQSR/expected/SNPDefaultTranches.txt, /gatkCloneMountPoint/src/test/resources/large/VQSR/snpRecal.vcf) 3.062s passed
testVariantRecalibratorSNP[2]([Ljava.lang.String;@d02c00, /gatkCloneMountPoint/src/test/resources/org/broadinstitute/hellbender/tools/walkers/VQSR/expected.AS.tranches, /gatkCloneMountPoint/src/test/resources/large/VQSR/expected/expected.AS.recal.vcf) 0.484s passed
testVariantRecalibratorSNPscattered[0]([Ljava.lang.String;@44ae6b66) 3.195s passed
testVariantRecalibratorSampling 1.502s passed

Standard output

--------------------------------------------------------------------------------
[21:10:08] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[21:10:29] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorSampling/gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[21:10:31] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[21:10:34] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[21:10:34] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/gatkCloneMountPoint/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[21:10:34] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/gatkCloneMountPoint/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[21:10:34] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorIndel/gatkCloneMountPoint/src/test/resources/large/VQSR/combined.phase1.chr20.raw.indels.filtered.sites.1M-10M.vcf
--------------------------------------------------------------------------------
[21:10:35] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[21:11:40] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf

Standard error

[June 12, 2025 at 9:10:12 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.07 minutes.
Runtime.totalMemory()=1059061760
21:10:12.924 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:12.924 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:12.924 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:12.924 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:12.924 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:12.925 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:12 PM GMT
21:10:12.925 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:12.925 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:12.925 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:12.925 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:12.925 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:12.925 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:12.926 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:12.926 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:12.926 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:12.926 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:12.926 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:12.926 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:12.926 INFO  VariantRecalibrator - Requester pays: disabled
21:10:12.926 INFO  VariantRecalibrator - Initializing engine
21:10:12.929 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:12.945 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:13.003 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
21:10:13.023 INFO  VariantRecalibrator - Done initializing engine
21:10:13.024 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:13.049 INFO  ProgressMeter - Starting traversal
21:10:13.049 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:13.187 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1222335.8
21:10:13.187 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
21:10:13.187 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
21:10:13.188 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
21:10:13.189 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
21:10:13.190 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
21:10:13.195 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
21:10:13.195 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
21:10:13.195 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:13.225 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:13.243 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.16919
21:10:13.260 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.14268
21:10:13.277 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.19617
21:10:13.294 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.09047
21:10:13.311 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.05235
21:10:13.328 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04028
21:10:13.345 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02103
21:10:13.361 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01461
21:10:13.378 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01136
21:10:13.396 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00583
21:10:13.413 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00291
21:10:13.423 INFO  VariantRecalibratorEngine - Convergence after 58 iterations!
21:10:13.425 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
21:10:13.438 INFO  VariantDataManager - Selected worst 0 scoring variants --> variants with LOD <= -5.5000.
21:10:13.447 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:13 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1059061760
21:10:13.451 INFO  gatk - Initializing VQSR tests/resetting random number generator
21:10:13.484 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:13.484 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:13.484 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:13.485 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:13.485 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:13.485 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:13 PM GMT
21:10:13.485 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:13.485 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:13.485 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:13.486 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:13.486 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:13.486 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:13.486 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:13.486 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:13.486 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:13.486 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:13.486 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:13.486 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:13.486 INFO  VariantRecalibrator - Requester pays: disabled
21:10:13.486 INFO  VariantRecalibrator - Initializing engine
21:10:13.488 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
21:10:13.493 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
21:10:13.495 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
21:10:13.498 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
21:10:13.504 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
21:10:13.505 INFO  VariantRecalibrator - Done initializing engine
21:10:13.507 WARN  VariantDataManager - Ignoring duplicate annotations for recalibration [HRun]
21:10:13.507 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
21:10:13.507 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:13.507 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
21:10:13.510 INFO  ProgressMeter - Starting traversal
21:10:13.510 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:14.896 INFO  ProgressMeter -           20:9944766              0.0                131821        5706536.8
21:10:14.896 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
21:10:14.902 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
21:10:14.908 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
21:10:14.912 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
21:10:14.955 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
21:10:14.957 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
21:10:14.958 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:15.205 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:15.309 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
21:10:15.421 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
21:10:15.531 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
21:10:15.640 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
21:10:15.751 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
21:10:15.859 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
21:10:15.972 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
21:10:16.092 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
21:10:16.180 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
21:10:16.267 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
21:10:16.337 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
21:10:16.344 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:16.417 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
21:10:16.417 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:16.419 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:16.419 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
21:10:16.421 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:16.610 INFO  TrancheManager - Finding 4 tranches for 131821 variants
21:10:16.643 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
21:10:16.649 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
21:10:16.649 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=100.00 minVQSLod=-240.7209 known=(59500 @ 2.2991) novel=(72321 @ 2.2239) truthSites(18665 accessible, 18665 called), name=anonymous]
21:10:16.649 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
21:10:16.654 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
21:10:16.654 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.90 minVQSLod=-3.1318 known=(59151 @ 2.3066) novel=(71923 @ 2.2295) truthSites(18665 accessible, 18646 called), name=anonymous]
21:10:16.655 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
21:10:16.661 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
21:10:16.661 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=2.2535 known=(57628 @ 2.3617) novel=(68589 @ 2.2769) truthSites(18665 accessible, 18478 called), name=anonymous]
21:10:16.661 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
21:10:16.672 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
21:10:16.672 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=90.00 minVQSLod=7.6928 known=(45852 @ 2.4660) novel=(22477 @ 2.4146) truthSites(18665 accessible, 16798 called), name=anonymous]
21:10:16.673 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:17.195 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:17 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.06 minutes.
Runtime.totalMemory()=1059061760
21:10:17.289 INFO  gatk - Initializing VQSR tests/resetting random number generator
21:10:17.326 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:17.326 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:17.326 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:17.326 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:17.326 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:17.327 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:17 PM GMT
21:10:17.327 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:17.327 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:17.327 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:17.327 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:17.327 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:17.327 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:17.327 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:17.327 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:17.327 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:17.328 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:17.328 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:17.328 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:17.328 INFO  VariantRecalibrator - Requester pays: disabled
21:10:17.328 INFO  VariantRecalibrator - Initializing engine
21:10:17.330 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
21:10:17.333 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
21:10:17.336 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
21:10:17.342 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
21:10:17.347 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
21:10:17.348 INFO  VariantRecalibrator - Done initializing engine
21:10:17.348 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
21:10:17.348 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:17.348 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
21:10:17.350 INFO  ProgressMeter - Starting traversal
21:10:17.350 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:18.368 INFO  ProgressMeter -           20:9944766              0.0                131821        7769410.6
21:10:18.368 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
21:10:18.371 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
21:10:18.375 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
21:10:18.378 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
21:10:18.398 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
21:10:18.400 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
21:10:18.400 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:18.642 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:18.745 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
21:10:18.850 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
21:10:18.957 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
21:10:19.066 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
21:10:19.179 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
21:10:19.264 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
21:10:19.351 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
21:10:19.438 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
21:10:19.524 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
21:10:19.611 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
21:10:19.681 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
21:10:19.688 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:19.760 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
21:10:19.760 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:19.762 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:19.762 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
21:10:19.764 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:19.948 INFO  TrancheManager - Finding 4 tranches for 131821 variants
21:10:19.980 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
21:10:19.984 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
21:10:19.985 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=100.00 minVQSLod=-240.7209 known=(59500 @ 2.2991) novel=(72321 @ 2.2239) truthSites(18665 accessible, 18665 called), name=anonymous]
21:10:19.985 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
21:10:19.989 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
21:10:19.989 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.90 minVQSLod=-3.1318 known=(59151 @ 2.3066) novel=(71923 @ 2.2295) truthSites(18665 accessible, 18646 called), name=anonymous]
21:10:19.989 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
21:10:19.994 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
21:10:19.994 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=2.2535 known=(57628 @ 2.3617) novel=(68589 @ 2.2769) truthSites(18665 accessible, 18478 called), name=anonymous]
21:10:19.994 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
21:10:19.998 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
21:10:19.998 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=90.00 minVQSLod=7.6928 known=(45852 @ 2.4660) novel=(22477 @ 2.4146) truthSites(18665 accessible, 16798 called), name=anonymous]
21:10:19.999 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:20.328 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:20 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1059061760
21:10:20.352 INFO  gatk - Initializing VQSR tests/resetting random number generator
21:10:20.371 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:20.371 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:20.371 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:20.372 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:20.372 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:20.372 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:20 PM GMT
21:10:20.372 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:20.372 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:20.372 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:20.372 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:20.372 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:20.372 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:20.373 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:20.373 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:20.373 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:20.373 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:20.373 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:20.373 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:20.373 INFO  VariantRecalibrator - Requester pays: disabled
21:10:20.373 INFO  VariantRecalibrator - Initializing engine
21:10:20.374 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:20.386 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:20.439 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
21:10:20.458 INFO  VariantRecalibrator - Done initializing engine
21:10:20.459 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:20.472 INFO  ProgressMeter - Starting traversal
21:10:20.473 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:20.523 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3349200.0
21:10:20.523 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
21:10:20.523 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
21:10:20.524 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
21:10:20.524 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
21:10:20.524 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
21:10:20.525 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
21:10:20.525 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
21:10:20.525 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:20.557 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:20.574 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
21:10:20.591 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
21:10:20.607 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
21:10:20.624 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
21:10:20.641 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
21:10:20.657 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
21:10:20.676 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
21:10:20.692 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
21:10:20.709 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
21:10:20.725 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
21:10:20.742 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
21:10:20.759 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
21:10:20.759 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
21:10:20.760 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
21:10:20.770 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
21:10:20.770 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:20.771 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:20.771 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
21:10:20.771 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
21:10:20.784 INFO  TrancheManager - Finding 4 tranches for 2786 variants
21:10:20.786 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
21:10:20.786 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
21:10:20.786 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=100.00 minVQSLod=-39326.4087 known=(0 @ 0.0000) novel=(2786 @ 3.2340) truthSites(2786 accessible, 2786 called), name=anonymous]
21:10:20.786 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
21:10:20.787 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
21:10:20.787 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.90 minVQSLod=-12.9282 known=(0 @ 0.0000) novel=(2783 @ 3.2295) truthSites(2786 accessible, 2783 called), name=anonymous]
21:10:20.787 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
21:10:20.787 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
21:10:20.787 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=626.3145 known=(0 @ 0.0000) novel=(2758 @ 3.2562) truthSites(2786 accessible, 2758 called), name=anonymous]
21:10:20.787 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
21:10:20.788 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
21:10:20.788 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=90.00 minVQSLod=935.3268 known=(0 @ 0.0000) novel=(2507 @ 3.2134) truthSites(2786 accessible, 2507 called), name=anonymous]
21:10:20.788 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:20.832 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:20 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1059061760
21:10:20.837 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 12, 2025 at 9:10:23 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1059061760
21:10:23.356 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:23.356 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:23.356 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:23.356 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:23.356 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:23.356 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:23 PM GMT
21:10:23.356 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:23.356 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:23.357 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:23.357 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:23.357 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:23.357 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:23.357 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:23.357 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:23.357 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:23.357 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:23.357 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:23.357 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:23.357 INFO  VariantRecalibrator - Requester pays: disabled
21:10:23.357 INFO  VariantRecalibrator - Initializing engine
21:10:23.359 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
21:10:23.362 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
21:10:23.364 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
21:10:23.366 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
21:10:23.369 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/g94982_20_1m_10m_python_2dcnn.indels.vcf.gz
21:10:23.390 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
21:10:23.392 INFO  VariantRecalibrator - Done initializing engine
21:10:23.392 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
21:10:23.392 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:23.392 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
21:10:23.396 INFO  ProgressMeter - Starting traversal
21:10:23.396 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:24.422 INFO  ProgressMeter -           20:9938789              0.0                134919        7890000.0
21:10:24.422 INFO  ProgressMeter - Traversal complete. Processed 134919 total variants in 0.0 minutes.
21:10:24.425 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
21:10:24.428 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
21:10:24.431 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
21:10:24.453 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
21:10:24.454 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
21:10:24.454 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:24.649 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:24.729 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.13181
21:10:24.811 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.46782
21:10:24.894 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 9.04961
21:10:24.980 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.04477
21:10:25.067 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01711
21:10:25.154 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.02053
21:10:25.241 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.01194
21:10:25.329 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01038
21:10:25.416 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.06192
21:10:25.507 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01281
21:10:25.575 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00457
21:10:25.603 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
21:10:25.608 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
21:10:25.722 INFO  VariantDataManager - Selected worst 754 scoring variants --> variants with LOD <= -5.0000.
21:10:25.722 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:25.724 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:25.725 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.05287
21:10:25.727 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.02030
21:10:25.728 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.00986
21:10:25.729 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.00749
21:10:25.730 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.00850
21:10:25.731 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01430
21:10:25.733 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02541
21:10:25.734 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.02173
21:10:25.735 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01024
21:10:25.736 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00479
21:10:25.737 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00245
21:10:25.738 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
21:10:25.740 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
21:10:25.919 INFO  TrancheManager - Finding 4 tranches for 134603 variants
21:10:25.967 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
21:10:25.972 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
21:10:25.972 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=100.00 minVQSLod=-246.6082 known=(61809 @ 2.2991) novel=(72794 @ 2.2239) truthSites(18665 accessible, 18665 called), name=anonymous]
21:10:25.972 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
21:10:25.977 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 649; running score is 0.001 
21:10:25.977 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.90 minVQSLod=-4.2626 known=(61478 @ 2.3089) novel=(72476 @ 2.2282) truthSites(18665 accessible, 18646 called), name=anonymous]
21:10:25.977 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
21:10:25.981 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 7924; running score is 0.010 
21:10:25.981 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=0.6000 known=(59416 @ 2.3515) novel=(67263 @ 2.2813) truthSites(18665 accessible, 18478 called), name=anonymous]
21:10:25.981 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
21:10:25.986 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 52632; running score is 0.100 
21:10:25.986 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=90.00 minVQSLod=4.4668 known=(48943 @ 2.4389) novel=(33028 @ 2.3795) truthSites(18665 accessible, 16798 called), name=anonymous]
21:10:25.986 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:26.303 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:26 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1059061760
21:10:26.305 INFO  gatk - Initializing VQSR tests/resetting random number generator
21:10:26.325 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:26.325 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:26.325 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:26.325 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:26.325 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:26.325 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:26 PM GMT
21:10:26.325 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:26.325 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:26.326 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:26.326 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:26.326 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:26.326 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:26.326 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:26.326 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:26.326 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:26.326 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:26.326 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:26.326 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:26.326 INFO  VariantRecalibrator - Requester pays: disabled
21:10:26.326 INFO  VariantRecalibrator - Initializing engine
21:10:26.328 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
21:10:26.329 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
21:10:26.331 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
21:10:26.332 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
21:10:26.335 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
21:10:26.336 INFO  VariantRecalibrator - Done initializing engine
21:10:26.336 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
21:10:26.336 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:26.336 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
21:10:26.337 INFO  ProgressMeter - Starting traversal
21:10:26.337 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:27.302 INFO  ProgressMeter -           20:9944766              0.0                131821        8196124.4
21:10:27.302 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
21:10:27.305 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
21:10:27.309 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
21:10:27.311 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
21:10:27.331 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
21:10:27.332 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
21:10:27.333 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:27.576 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:27.680 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
21:10:27.786 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
21:10:27.894 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
21:10:28.004 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
21:10:28.118 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
21:10:28.227 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
21:10:28.338 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
21:10:28.451 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
21:10:28.539 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
21:10:28.626 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
21:10:28.696 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
21:10:28.703 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:28.774 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
21:10:28.775 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:28.776 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:28.777 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
21:10:28.778 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:28.964 INFO  TrancheManager - Finding 12 tranches for 131821 variants
21:10:29.002 INFO  TrancheManager -   VQSLODTranche threshold 10.00 => selection metric threshold 0.900
21:10:29.016 INFO  TrancheManager -   Found tranche for 10.000: 0.900 threshold starting with variant 97819; running score is 0.262 
21:10:29.016 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=10.0000 known=(29048 @ 2.5026) novel=(4954 @ 2.3633) truthSites(18665 accessible, 13780 called), name=anonymous]
21:10:29.016 INFO  TrancheManager -   VQSLODTranche threshold 8.00 => selection metric threshold 0.920
21:10:29.030 INFO  TrancheManager -   Found tranche for 8.000: 0.920 threshold starting with variant 68875; running score is 0.114 
21:10:29.030 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=8.0000 known=(44004 @ 2.4829) novel=(18942 @ 2.4147) truthSites(18665 accessible, 16543 called), name=anonymous]
21:10:29.030 INFO  TrancheManager -   VQSLODTranche threshold 6.00 => selection metric threshold 0.940
21:10:29.040 INFO  TrancheManager -   Found tranche for 6.000: 0.940 threshold starting with variant 34094; running score is 0.052 
21:10:29.040 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=6.0000 known=(52474 @ 2.4242) novel=(45253 @ 2.3994) truthSites(18665 accessible, 17701 called), name=anonymous]
21:10:29.040 INFO  TrancheManager -   VQSLODTranche threshold 4.00 => selection metric threshold 0.960
21:10:29.050 INFO  TrancheManager -   Found tranche for 4.000: 0.960 threshold starting with variant 12275; running score is 0.023 
21:10:29.050 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=4.0000 known=(56181 @ 2.3913) novel=(63365 @ 2.3212) truthSites(18665 accessible, 18243 called), name=anonymous]
21:10:29.050 INFO  TrancheManager -   VQSLODTranche threshold 2.00 => selection metric threshold 0.980
21:10:29.059 INFO  TrancheManager -   Found tranche for 2.000: 0.980 threshold starting with variant 4952; running score is 0.009 
21:10:29.060 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=2.0000 known=(57758 @ 2.3573) novel=(69111 @ 2.2722) truthSites(18665 accessible, 18502 called), name=anonymous]
21:10:29.060 INFO  TrancheManager -   VQSLODTranche threshold 0.00 => selection metric threshold 1.000
21:10:29.074 INFO  TrancheManager -   Found tranche for 0.000: 1.000 threshold starting with variant 2260; running score is 0.004 
21:10:29.074 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=0.0000 known=(58579 @ 2.3306) novel=(70982 @ 2.2511) truthSites(18665 accessible, 18598 called), name=anonymous]
21:10:29.074 INFO  TrancheManager -   VQSLODTranche threshold -2.00 => selection metric threshold 1.020
21:10:29.085 INFO  TrancheManager -   Found tranche for -2.000: 1.020 threshold starting with variant 1099; running score is 0.001 
21:10:29.085 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-2.0000 known=(59019 @ 2.3111) novel=(71703 @ 2.2372) truthSites(18665 accessible, 18640 called), name=anonymous]
21:10:29.085 INFO  TrancheManager -   VQSLODTranche threshold -4.00 => selection metric threshold 1.040
21:10:29.096 INFO  TrancheManager -   Found tranche for -4.000: 1.040 threshold starting with variant 606; running score is 0.001 
21:10:29.096 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-4.0000 known=(59205 @ 2.3054) novel=(72010 @ 2.2272) truthSites(18665 accessible, 18648 called), name=anonymous]
21:10:29.096 INFO  TrancheManager -   VQSLODTranche threshold -6.00 => selection metric threshold 1.060
21:10:29.105 INFO  TrancheManager -   Found tranche for -6.000: 1.060 threshold starting with variant 429; running score is 0.001 
21:10:29.105 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-6.0000 known=(59292 @ 2.3026) novel=(72100 @ 2.2261) truthSites(18665 accessible, 18653 called), name=anonymous]
21:10:29.105 INFO  TrancheManager -   VQSLODTranche threshold -8.00 => selection metric threshold 1.080
21:10:29.111 INFO  TrancheManager -   Found tranche for -8.000: 1.080 threshold starting with variant 314; running score is 0.000 
21:10:29.111 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-8.0000 known=(59355 @ 2.3009) novel=(72152 @ 2.2247) truthSites(18665 accessible, 18657 called), name=anonymous]
21:10:29.111 INFO  TrancheManager -   VQSLODTranche threshold -10.00 => selection metric threshold 1.100
21:10:29.116 INFO  TrancheManager -   Found tranche for -10.000: 1.100 threshold starting with variant 264; running score is 0.000 
21:10:29.116 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-10.0000 known=(59372 @ 2.3008) novel=(72185 @ 2.2246) truthSites(18665 accessible, 18658 called), name=anonymous]
21:10:29.116 INFO  TrancheManager -   VQSLODTranche threshold -12.00 => selection metric threshold 1.120
21:10:29.123 INFO  TrancheManager -   Found tranche for -12.000: 1.120 threshold starting with variant 211; running score is 0.000 
21:10:29.123 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-12.0000 known=(59394 @ 2.3004) novel=(72216 @ 2.2244) truthSites(18665 accessible, 18659 called), name=anonymous]
21:10:29.123 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:29.457 INFO  VariantRecalibrator - Tranches plot will not be generated since we are running in scattered mode
21:10:29.464 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:29 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1059061760
21:10:29.501 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 12, 2025 at 9:10:30 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1059061760
21:10:31.025 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:31.025 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:31.025 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:31.025 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:31.025 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:31.025 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:31 PM GMT
21:10:31.025 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:31.025 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:31.026 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:31.026 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:31.026 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:31.026 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:31.026 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:31.026 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:31.026 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:31.026 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:31.026 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:31.026 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:31.026 INFO  VariantRecalibrator - Requester pays: disabled
21:10:31.026 INFO  VariantRecalibrator - Initializing engine
21:10:31.028 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:31.039 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:31.076 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
21:10:31.092 INFO  VariantRecalibrator - Done initializing engine
21:10:31.092 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:31.106 INFO  ProgressMeter - Starting traversal
21:10:31.106 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:31.164 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        2887241.4
21:10:31.164 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
21:10:31.164 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
21:10:31.164 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
21:10:31.164 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
21:10:31.165 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
21:10:31.165 INFO  VariantDataManager - AS_FS: 	 mean = 1.08	 standard deviation = 2.43
21:10:31.165 INFO  VariantDataManager - AS_MQRankSum: 	 mean = 0.00	 standard deviation = 0.01
21:10:31.166 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR, AS_FS, AS_MQRankSum]
21:10:31.166 INFO  VariantDataManager - Training with 2769 variants after standard deviation thresholding.
21:10:31.166 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:31.200 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:31.226 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.56007
21:10:31.251 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.67355
21:10:31.275 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 5.08559
21:10:31.300 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.01567
21:10:31.325 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.02021
21:10:31.350 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01989
21:10:31.375 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02504
21:10:31.400 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03657
21:10:31.425 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.04057
21:10:31.450 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.08648
21:10:31.476 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.01514
21:10:31.501 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00496
21:10:31.526 INFO  VariantRecalibratorEngine - Finished iteration 65. 	Current change in mixture coefficients = 0.00163
21:10:31.526 INFO  VariantRecalibratorEngine - Convergence after 65 iterations!
21:10:31.530 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
21:10:31.550 INFO  VariantDataManager - Selected worst 5 scoring variants --> variants with LOD <= -5.0000.
21:10:31.551 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:31.551 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:31.551 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
21:10:31.551 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
21:10:31.565 INFO  TrancheManager - Finding 4 tranches for 2786 variants
21:10:31.566 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
21:10:31.566 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
21:10:31.566 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=100.00 minVQSLod=-39314.8821 known=(0 @ 0.0000) novel=(2786 @ 3.2340) truthSites(2786 accessible, 2786 called), name=anonymous]
21:10:31.566 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
21:10:31.566 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
21:10:31.566 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.90 minVQSLod=-16.8308 known=(0 @ 0.0000) novel=(2783 @ 3.2295) truthSites(2786 accessible, 2783 called), name=anonymous]
21:10:31.566 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
21:10:31.566 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
21:10:31.566 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=1239951.3360 known=(0 @ 0.0000) novel=(2758 @ 3.2496) truthSites(2786 accessible, 2758 called), name=anonymous]
21:10:31.566 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
21:10:31.567 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
21:10:31.567 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=90.00 minVQSLod=2091223.5520 known=(0 @ 0.0000) novel=(2507 @ 3.2205) truthSites(2786 accessible, 2507 called), name=anonymous]
21:10:31.567 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:31.584 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:31 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1059061760
21:10:31.586 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 12, 2025 at 9:10:34 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1059061760
[June 12, 2025 at 9:10:34 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1059061760
[June 12, 2025 at 9:10:34 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1059061760
[June 12, 2025 at 9:10:34 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1059061760
[June 12, 2025 at 9:10:35 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1059061760
[June 12, 2025 at 9:10:36 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1059061760
21:10:36.906 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:36.906 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:36.906 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:36.907 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:36.907 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:36.907 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:36 PM GMT
21:10:36.907 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:36.907 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:36.907 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:36.907 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:36.907 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:36.907 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:36.907 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:36.907 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:36.907 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:36.907 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:36.907 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:36.907 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:36.907 INFO  VariantRecalibrator - Requester pays: disabled
21:10:36.907 INFO  VariantRecalibrator - Initializing engine
21:10:36.908 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
21:10:36.910 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
21:10:36.912 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
21:10:36.913 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
21:10:36.915 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
21:10:36.916 INFO  VariantRecalibrator - Done initializing engine
21:10:36.916 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
21:10:36.916 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:36.916 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
21:10:36.917 INFO  ProgressMeter - Starting traversal
21:10:36.917 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:37.878 INFO  ProgressMeter -           20:9944766              0.0                131821        8230239.3
21:10:37.878 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
21:10:37.880 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
21:10:37.883 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
21:10:37.885 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
21:10:37.906 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
21:10:37.907 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
21:10:37.907 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:38.148 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:38.252 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
21:10:38.357 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
21:10:38.467 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
21:10:38.575 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
21:10:38.683 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
21:10:38.790 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
21:10:38.900 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
21:10:39.011 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
21:10:39.097 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
21:10:39.184 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
21:10:39.254 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
21:10:39.261 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:39.327 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
21:10:39.327 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:39.329 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:39.329 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
21:10:39.331 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
21:10:39.511 INFO  TrancheManager - Finding 12 tranches for 131821 variants
21:10:39.544 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
21:10:39.549 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
21:10:39.549 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=100.00 minVQSLod=-240.7209 known=(59500 @ 2.2991) novel=(72321 @ 2.2239) truthSites(18665 accessible, 18665 called), name=anonymous]
21:10:39.549 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
21:10:39.553 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 381; running score is 0.001 
21:10:39.553 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.95 minVQSLod=-6.6729 known=(59316 @ 2.3020) novel=(72124 @ 2.2259) truthSites(18665 accessible, 18655 called), name=anonymous]
21:10:39.553 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
21:10:39.557 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
21:10:39.557 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.90 minVQSLod=-3.1318 known=(59151 @ 2.3066) novel=(71923 @ 2.2295) truthSites(18665 accessible, 18646 called), name=anonymous]
21:10:39.557 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
21:10:39.562 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 1480; running score is 0.002 
21:10:39.562 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.80 minVQSLod=-1.1986 known=(58885 @ 2.3181) novel=(71456 @ 2.2416) truthSites(18665 accessible, 18627 called), name=anonymous]
21:10:39.562 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
21:10:39.566 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 2377; running score is 0.004 
21:10:39.566 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.60 minVQSLod=0.1656 known=(58528 @ 2.3328) novel=(70916 @ 2.2530) truthSites(18665 accessible, 18590 called), name=anonymous]
21:10:39.566 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
21:10:39.571 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 3042; running score is 0.005 
21:10:39.571 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.50 minVQSLod=0.9426 known=(58256 @ 2.3427) novel=(70523 @ 2.2598) truthSites(18665 accessible, 18571 called), name=anonymous]
21:10:39.571 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
21:10:39.575 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 3577; running score is 0.006 
21:10:39.575 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.40 minVQSLod=1.3251 known=(58072 @ 2.3504) novel=(70172 @ 2.2640) truthSites(18665 accessible, 18553 called), name=anonymous]
21:10:39.575 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
21:10:39.580 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 4004; running score is 0.007 
21:10:39.580 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.30 minVQSLod=1.5909 known=(57947 @ 2.3539) novel=(69870 @ 2.2668) truthSites(18665 accessible, 18534 called), name=anonymous]
21:10:39.580 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
21:10:39.584 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
21:10:39.584 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=2.2535 known=(57628 @ 2.3617) novel=(68589 @ 2.2769) truthSites(18665 accessible, 18478 called), name=anonymous]
21:10:39.584 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
21:10:39.588 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 10673; running score is 0.020 
21:10:39.588 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=98.00 minVQSLod=3.7431 known=(56497 @ 2.3862) novel=(64651 @ 2.3078) truthSites(18665 accessible, 18291 called), name=anonymous]
21:10:39.588 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
21:10:39.595 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 16985; running score is 0.030 
21:10:39.595 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=97.00 minVQSLod=4.6404 known=(55330 @ 2.4003) novel=(59506 @ 2.3526) truthSites(18665 accessible, 18105 called), name=anonymous]
21:10:39.595 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
21:10:39.601 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
21:10:39.601 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=90.00 minVQSLod=7.6928 known=(45852 @ 2.4660) novel=(22477 @ 2.4146) truthSites(18665 accessible, 16798 called), name=anonymous]
21:10:39.602 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:39.899 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:39 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1059061760
21:10:39.930 INFO  gatk - Initializing VQSR tests/resetting random number generator
21:10:39.952 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:39.952 INFO  VariantRecalibrator - The Genome Analysis Toolkit (GATK) v4.6.2.0-8-g092bdf2-SNAPSHOT
21:10:39.952 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
21:10:39.952 INFO  VariantRecalibrator - Executing as root@e24cea241624 on Linux v6.11.0-1015-azure amd64
21:10:39.952 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.12+7-Ubuntu-1ubuntu222.04
21:10:39.953 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 9:10:39 PM GMT
21:10:39.953 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:39.953 INFO  VariantRecalibrator - ------------------------------------------------------------
21:10:39.953 INFO  VariantRecalibrator - HTSJDK Version: 4.2.0
21:10:39.953 INFO  VariantRecalibrator - Picard Version: 3.4.0
21:10:39.953 INFO  VariantRecalibrator - Built for Spark Version: 3.5.0
21:10:39.953 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
21:10:39.953 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
21:10:39.953 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
21:10:39.953 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
21:10:39.953 INFO  VariantRecalibrator - Deflater: IntelDeflater
21:10:39.953 INFO  VariantRecalibrator - Inflater: IntelInflater
21:10:39.953 INFO  VariantRecalibrator - GCS max retries/reopens: 20
21:10:39.953 INFO  VariantRecalibrator - Requester pays: disabled
21:10:39.953 INFO  VariantRecalibrator - Initializing engine
21:10:39.955 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:39.966 INFO  FeatureManager - Using codec VCFCodec to read file file:///gatkCloneMountPoint/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
21:10:40.001 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
21:10:40.014 INFO  VariantRecalibrator - Done initializing engine
21:10:40.014 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
21:10:40.024 INFO  ProgressMeter - Starting traversal
21:10:40.024 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
21:10:40.079 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3044727.3
21:10:40.079 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
21:10:40.080 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
21:10:40.080 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
21:10:40.080 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
21:10:40.080 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
21:10:40.081 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
21:10:40.081 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
21:10:40.081 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:40.111 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:40.128 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
21:10:40.144 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
21:10:40.160 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
21:10:40.177 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
21:10:40.194 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
21:10:40.210 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
21:10:40.227 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
21:10:40.243 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
21:10:40.260 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
21:10:40.276 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
21:10:40.292 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
21:10:40.309 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
21:10:40.309 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
21:10:40.311 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
21:10:40.319 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
21:10:40.319 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
21:10:40.319 INFO  VariantRecalibratorEngine - Finished iteration 0.
21:10:40.319 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
21:10:40.319 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
21:10:40.327 INFO  TrancheManager - Finding 12 tranches for 2786 variants
21:10:40.328 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
21:10:40.328 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
21:10:40.328 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=100.00 minVQSLod=-39326.4087 known=(0 @ 0.0000) novel=(2786 @ 3.2340) truthSites(2786 accessible, 2786 called), name=anonymous]
21:10:40.328 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
21:10:40.328 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 2; running score is 0.001 
21:10:40.328 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.95 minVQSLod=-22753.7269 known=(0 @ 0.0000) novel=(2784 @ 3.2310) truthSites(2786 accessible, 2784 called), name=anonymous]
21:10:40.328 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
21:10:40.328 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.90 minVQSLod=-12.9282 known=(0 @ 0.0000) novel=(2783 @ 3.2295) truthSites(2786 accessible, 2783 called), name=anonymous]
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
21:10:40.329 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 6; running score is 0.002 
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.80 minVQSLod=-5.7548 known=(0 @ 0.0000) novel=(2780 @ 3.2314) truthSites(2786 accessible, 2780 called), name=anonymous]
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
21:10:40.329 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 12; running score is 0.004 
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.60 minVQSLod=250.6941 known=(0 @ 0.0000) novel=(2774 @ 3.2481) truthSites(2786 accessible, 2774 called), name=anonymous]
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
21:10:40.329 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 14; running score is 0.005 
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.50 minVQSLod=342.2903 known=(0 @ 0.0000) novel=(2772 @ 3.2515) truthSites(2786 accessible, 2772 called), name=anonymous]
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
21:10:40.329 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 17; running score is 0.006 
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.40 minVQSLod=511.3402 known=(0 @ 0.0000) novel=(2769 @ 3.2469) truthSites(2786 accessible, 2769 called), name=anonymous]
21:10:40.329 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
21:10:40.330 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 20; running score is 0.007 
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.30 minVQSLod=573.6691 known=(0 @ 0.0000) novel=(2766 @ 3.2423) truthSites(2786 accessible, 2766 called), name=anonymous]
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
21:10:40.330 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=626.3145 known=(0 @ 0.0000) novel=(2758 @ 3.2562) truthSites(2786 accessible, 2758 called), name=anonymous]
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
21:10:40.330 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 56; running score is 0.020 
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=98.00 minVQSLod=710.0883 known=(0 @ 0.0000) novel=(2730 @ 3.2523) truthSites(2786 accessible, 2730 called), name=anonymous]
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
21:10:40.330 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 84; running score is 0.030 
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=97.00 minVQSLod=758.5107 known=(0 @ 0.0000) novel=(2702 @ 3.2484) truthSites(2786 accessible, 2702 called), name=anonymous]
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
21:10:40.330 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
21:10:40.330 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=90.00 minVQSLod=935.3268 known=(0 @ 0.0000) novel=(2507 @ 3.2134) truthSites(2786 accessible, 2507 called), name=anonymous]
21:10:40.331 INFO  VariantRecalibrator - Writing out recalibration table...
21:10:40.343 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 9:10:40 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1059061760
[June 12, 2025 at 9:11:42 PM GMT] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1059061760