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

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

tests
0

failures
0

ignored
33.671s

duration
100%

successful

Tests

Test Duration Result
testAnnotationsWithNoVarianceSpecified 0.700s passed
testBothAggregateRecalMode 5.231s passed
testBothRecalMode 2.467s passed
testInGatkLiteDocker 0.088s passed
testNoNegativeTrainingData 0.510s passed
testVQSRAnnotationOrder 0.220s passed
testVariantRecalibratorIndel 0.852s passed
testVariantRecalibratorModelInput 1.312s passed
testVariantRecalibratorRScriptOutput 1.588s passed
testVariantRecalibratorSNPAlternateTranches[0]([Ljava.lang.String;@553da911, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/expected/SNPAlternateTranches.txt, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/snpRecal.vcf) 3.204s passed
testVariantRecalibratorSNPAlternateTranches[1]([Ljava.lang.String;@19c1820d, /home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/VQSR/expected.AS.alternate.tranches, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/expected/expected.AS.recal.vcf) 0.394s passed
testVariantRecalibratorSNPMaxAttempts[0]([Ljava.lang.String;@996a546) 5.528s passed
testVariantRecalibratorSNP[0]([Ljava.lang.String;@4f169009, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/expected/SNPDefaultTranches.txt, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/snpRecal.vcf) 3.257s passed
testVariantRecalibratorSNP[1]([Ljava.lang.String;@553da911, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/expected/SNPDefaultTranches.txt, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/snpRecal.vcf) 3.200s passed
testVariantRecalibratorSNP[2]([Ljava.lang.String;@19c1820d, /home/runner/work/gatk/gatk/src/test/resources/org/broadinstitute/hellbender/tools/walkers/VQSR/expected.AS.tranches, /home/runner/work/gatk/gatk/src/test/resources/large/VQSR/expected/expected.AS.recal.vcf) 0.488s passed
testVariantRecalibratorSNPscattered[0]([Ljava.lang.String;@2db6d68d) 3.111s passed
testVariantRecalibratorSampling 1.521s passed

Standard output

--------------------------------------------------------------------------------
[20:55:06] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[20:55:28] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorSampling/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[20:55:30] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[20:55:32] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[20:55:32] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[20:55:32] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[20:55:33] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorIndel/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/combined.phase1.chr20.raw.indels.filtered.sites.1M-10M.vcf
--------------------------------------------------------------------------------
[20:55:33] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[20:56:46] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf

Standard error

[June 12, 2025 at 8:55:11 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.08 minutes.
Runtime.totalMemory()=994050048
20:55:12.003 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:12.004 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:12.004 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:12.004 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:12.004 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:12.004 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:12 PM UTC
20:55:12.005 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:12.005 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:12.005 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:12.005 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:12.005 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:12.005 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:12.005 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:12.005 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:12.005 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:12.006 INFO  VariantRecalibrator - Requester pays: disabled
20:55:12.006 INFO  VariantRecalibrator - Initializing engine
20:55:12.008 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:12.025 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:12.084 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
20:55:12.104 INFO  VariantRecalibrator - Done initializing engine
20:55:12.105 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:12.130 INFO  ProgressMeter - Starting traversal
20:55:12.131 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:12.222 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1840219.8
20:55:12.223 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
20:55:12.223 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
20:55:12.225 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
20:55:12.225 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
20:55:12.226 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
20:55:12.227 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
20:55:12.227 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
20:55:12.228 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:12.264 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:12.282 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.16919
20:55:12.299 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.14268
20:55:12.316 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.19617
20:55:12.334 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.09047
20:55:12.351 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.05235
20:55:12.368 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04028
20:55:12.384 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02103
20:55:12.413 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01461
20:55:12.428 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01136
20:55:12.444 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00583
20:55:12.459 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00291
20:55:12.468 INFO  VariantRecalibratorEngine - Convergence after 58 iterations!
20:55:12.470 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
20:55:12.480 INFO  VariantDataManager - Selected worst 0 scoring variants --> variants with LOD <= -5.5000.
20:55:12.489 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:12 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=994050048
20:55:12.495 INFO  gatk - Initializing VQSR tests/resetting random number generator
20:55:12.513 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:12.513 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:12.513 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:12.513 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:12.513 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:12.513 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:12 PM UTC
20:55:12.513 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:12.514 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:12.514 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:12.514 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:12.514 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:12.514 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:12.514 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:12.514 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:12.514 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:12.514 INFO  VariantRecalibrator - Requester pays: disabled
20:55:12.514 INFO  VariantRecalibrator - Initializing engine
20:55:12.516 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
20:55:12.520 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
20:55:12.523 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
20:55:12.525 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
20:55:12.531 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
20:55:12.532 INFO  VariantRecalibrator - Done initializing engine
20:55:12.534 WARN  VariantDataManager - Ignoring duplicate annotations for recalibration [HRun]
20:55:12.535 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
20:55:12.535 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:12.535 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
20:55:12.538 INFO  ProgressMeter - Starting traversal
20:55:12.539 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:13.611 INFO  ProgressMeter -           20:9944766              0.0                131821        7378041.0
20:55:13.611 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
20:55:13.617 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
20:55:13.624 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
20:55:13.631 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
20:55:13.671 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
20:55:13.674 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
20:55:13.674 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:13.944 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:14.050 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
20:55:14.172 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
20:55:14.259 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
20:55:14.348 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
20:55:14.437 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
20:55:14.525 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
20:55:14.615 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
20:55:14.706 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
20:55:14.796 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
20:55:14.901 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
20:55:14.977 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
20:55:14.983 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:15.053 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
20:55:15.053 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:15.055 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:15.055 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
20:55:15.057 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:15.236 INFO  TrancheManager - Finding 4 tranches for 131821 variants
20:55:15.274 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
20:55:15.285 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
20:55:15.285 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]
20:55:15.285 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
20:55:15.301 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
20:55:15.301 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]
20:55:15.302 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
20:55:15.315 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
20:55:15.315 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]
20:55:15.316 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
20:55:15.335 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
20:55:15.335 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]
20:55:15.335 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:15.712 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:15 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=994050048
20:55:15.753 INFO  gatk - Initializing VQSR tests/resetting random number generator
20:55:15.772 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:15.772 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:15.772 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:15.772 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:15.772 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:15.772 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:15 PM UTC
20:55:15.772 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:15.773 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:15.773 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:15.773 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:15.773 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:15.773 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:15.773 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:15.773 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:15.773 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:15.773 INFO  VariantRecalibrator - Requester pays: disabled
20:55:15.773 INFO  VariantRecalibrator - Initializing engine
20:55:15.775 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
20:55:15.779 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
20:55:15.782 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
20:55:15.789 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
20:55:15.794 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
20:55:15.795 INFO  VariantRecalibrator - Done initializing engine
20:55:15.796 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
20:55:15.796 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:15.796 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
20:55:15.798 INFO  ProgressMeter - Starting traversal
20:55:15.798 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:16.801 INFO  ProgressMeter -           20:9944766              0.0                131821        7885603.2
20:55:16.801 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
20:55:16.803 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
20:55:16.808 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
20:55:16.812 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
20:55:16.838 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
20:55:16.840 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
20:55:16.840 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:17.100 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:17.205 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
20:55:17.313 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
20:55:17.424 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
20:55:17.538 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
20:55:17.652 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
20:55:17.763 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
20:55:17.885 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
20:55:17.975 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
20:55:18.065 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
20:55:18.156 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
20:55:18.228 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
20:55:18.235 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:18.309 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
20:55:18.309 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:18.311 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:18.311 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
20:55:18.313 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:18.498 INFO  TrancheManager - Finding 4 tranches for 131821 variants
20:55:18.536 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
20:55:18.545 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
20:55:18.545 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]
20:55:18.546 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
20:55:18.555 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
20:55:18.556 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]
20:55:18.556 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
20:55:18.566 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
20:55:18.566 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]
20:55:18.566 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
20:55:18.581 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
20:55:18.581 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]
20:55:18.581 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:18.926 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:18 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1103101952
20:55:18.954 INFO  gatk - Initializing VQSR tests/resetting random number generator
20:55:18.964 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:18.964 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:18.965 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:18.965 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:18.965 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:18.965 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:18 PM UTC
20:55:18.965 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:18.965 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:18.965 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:18.965 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:18.965 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:18.965 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:18.965 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:18.965 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:18.966 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:18.966 INFO  VariantRecalibrator - Requester pays: disabled
20:55:18.966 INFO  VariantRecalibrator - Initializing engine
20:55:18.967 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:18.986 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:19.037 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
20:55:19.063 INFO  VariantRecalibrator - Done initializing engine
20:55:19.063 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:19.081 INFO  ProgressMeter - Starting traversal
20:55:19.081 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:19.153 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        2325833.3
20:55:19.154 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
20:55:19.154 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
20:55:19.154 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
20:55:19.155 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
20:55:19.155 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
20:55:19.156 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
20:55:19.156 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
20:55:19.156 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:19.189 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:19.205 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
20:55:19.222 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
20:55:19.238 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
20:55:19.255 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
20:55:19.272 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
20:55:19.288 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
20:55:19.305 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
20:55:19.321 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
20:55:19.338 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
20:55:19.354 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
20:55:19.370 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
20:55:19.387 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
20:55:19.387 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
20:55:19.388 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
20:55:19.403 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
20:55:19.403 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:19.403 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:19.404 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
20:55:19.404 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
20:55:19.415 INFO  TrancheManager - Finding 4 tranches for 2786 variants
20:55:19.416 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
20:55:19.416 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
20:55:19.416 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]
20:55:19.417 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
20:55:19.417 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
20:55:19.417 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]
20:55:19.417 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
20:55:19.417 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
20:55:19.417 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]
20:55:19.417 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
20:55:19.418 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
20:55:19.418 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]
20:55:19.418 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:19.439 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:19 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1103101952
20:55:19.444 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 12, 2025 at 8:55:22 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1103101952
20:55:22.031 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:22.031 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:22.031 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:22.031 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:22.031 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:22.031 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:22 PM UTC
20:55:22.031 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:22.031 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:22.031 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:22.032 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:22.032 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:22.032 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:22.032 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:22.032 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:22.032 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:22.032 INFO  VariantRecalibrator - Requester pays: disabled
20:55:22.032 INFO  VariantRecalibrator - Initializing engine
20:55:22.033 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
20:55:22.035 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
20:55:22.037 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
20:55:22.039 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
20:55:22.041 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/g94982_20_1m_10m_python_2dcnn.indels.vcf.gz
20:55:22.059 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
20:55:22.061 INFO  VariantRecalibrator - Done initializing engine
20:55:22.061 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
20:55:22.061 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:22.061 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
20:55:22.065 INFO  ProgressMeter - Starting traversal
20:55:22.065 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:23.076 INFO  ProgressMeter -           20:9938789              0.0                134919        8007062.3
20:55:23.077 INFO  ProgressMeter - Traversal complete. Processed 134919 total variants in 0.0 minutes.
20:55:23.079 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
20:55:23.085 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
20:55:23.090 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
20:55:23.129 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
20:55:23.131 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
20:55:23.131 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:23.321 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:23.394 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.13181
20:55:23.470 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.46782
20:55:23.550 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 9.04961
20:55:23.639 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.04477
20:55:23.722 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01711
20:55:23.804 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.02053
20:55:23.887 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.01194
20:55:23.967 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01038
20:55:24.047 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.06192
20:55:24.128 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01281
20:55:24.213 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00457
20:55:24.255 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
20:55:24.261 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
20:55:24.371 INFO  VariantDataManager - Selected worst 754 scoring variants --> variants with LOD <= -5.0000.
20:55:24.371 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:24.373 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:24.374 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.05287
20:55:24.376 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.02030
20:55:24.377 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.00986
20:55:24.378 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.00749
20:55:24.379 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.00850
20:55:24.380 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01430
20:55:24.381 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02541
20:55:24.383 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.02173
20:55:24.384 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01024
20:55:24.385 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00479
20:55:24.386 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00245
20:55:24.387 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
20:55:24.388 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
20:55:24.589 INFO  TrancheManager - Finding 4 tranches for 134603 variants
20:55:24.631 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
20:55:24.637 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
20:55:24.637 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]
20:55:24.637 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
20:55:24.642 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 649; running score is 0.001 
20:55:24.642 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]
20:55:24.642 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
20:55:24.651 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 7924; running score is 0.010 
20:55:24.651 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]
20:55:24.651 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
20:55:24.658 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 52632; running score is 0.100 
20:55:24.658 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]
20:55:24.658 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:24.973 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:24 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1103101952
20:55:24.974 INFO  gatk - Initializing VQSR tests/resetting random number generator
20:55:24.982 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:24.982 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:24.982 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:24.983 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:24.983 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:24.983 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:24 PM UTC
20:55:24.983 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:24.983 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:24.983 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:24.983 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:24.983 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:24.983 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:24.983 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:24.983 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:24.984 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:24.984 INFO  VariantRecalibrator - Requester pays: disabled
20:55:24.984 INFO  VariantRecalibrator - Initializing engine
20:55:24.985 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
20:55:24.986 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
20:55:24.988 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
20:55:24.989 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
20:55:24.993 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
20:55:24.994 INFO  VariantRecalibrator - Done initializing engine
20:55:24.994 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
20:55:24.994 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:24.995 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
20:55:24.996 INFO  ProgressMeter - Starting traversal
20:55:24.996 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:25.953 INFO  ProgressMeter -           20:9944766              0.0                131821        8264639.5
20:55:25.954 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
20:55:25.956 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
20:55:25.961 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
20:55:25.966 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
20:55:25.993 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
20:55:25.995 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
20:55:25.995 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:26.258 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:26.373 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
20:55:26.494 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
20:55:26.579 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
20:55:26.665 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
20:55:26.754 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
20:55:26.842 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
20:55:26.931 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
20:55:27.021 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
20:55:27.110 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
20:55:27.199 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
20:55:27.271 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
20:55:27.278 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:27.351 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
20:55:27.351 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:27.354 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:27.355 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
20:55:27.357 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:27.545 INFO  TrancheManager - Finding 12 tranches for 131821 variants
20:55:27.591 INFO  TrancheManager -   VQSLODTranche threshold 10.00 => selection metric threshold 0.900
20:55:27.610 INFO  TrancheManager -   Found tranche for 10.000: 0.900 threshold starting with variant 97819; running score is 0.262 
20:55:27.610 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=10.0000 known=(29048 @ 2.5026) novel=(4954 @ 2.3633) truthSites(18665 accessible, 13780 called), name=anonymous]
20:55:27.610 INFO  TrancheManager -   VQSLODTranche threshold 8.00 => selection metric threshold 0.920
20:55:27.622 INFO  TrancheManager -   Found tranche for 8.000: 0.920 threshold starting with variant 68875; running score is 0.114 
20:55:27.623 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=8.0000 known=(44004 @ 2.4829) novel=(18942 @ 2.4147) truthSites(18665 accessible, 16543 called), name=anonymous]
20:55:27.623 INFO  TrancheManager -   VQSLODTranche threshold 6.00 => selection metric threshold 0.940
20:55:27.636 INFO  TrancheManager -   Found tranche for 6.000: 0.940 threshold starting with variant 34094; running score is 0.052 
20:55:27.636 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=6.0000 known=(52474 @ 2.4242) novel=(45253 @ 2.3994) truthSites(18665 accessible, 17701 called), name=anonymous]
20:55:27.636 INFO  TrancheManager -   VQSLODTranche threshold 4.00 => selection metric threshold 0.960
20:55:27.654 INFO  TrancheManager -   Found tranche for 4.000: 0.960 threshold starting with variant 12275; running score is 0.023 
20:55:27.654 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=4.0000 known=(56181 @ 2.3913) novel=(63365 @ 2.3212) truthSites(18665 accessible, 18243 called), name=anonymous]
20:55:27.655 INFO  TrancheManager -   VQSLODTranche threshold 2.00 => selection metric threshold 0.980
20:55:27.668 INFO  TrancheManager -   Found tranche for 2.000: 0.980 threshold starting with variant 4952; running score is 0.009 
20:55:27.668 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=2.0000 known=(57758 @ 2.3573) novel=(69111 @ 2.2722) truthSites(18665 accessible, 18502 called), name=anonymous]
20:55:27.668 INFO  TrancheManager -   VQSLODTranche threshold 0.00 => selection metric threshold 1.000
20:55:27.680 INFO  TrancheManager -   Found tranche for 0.000: 1.000 threshold starting with variant 2260; running score is 0.004 
20:55:27.681 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=0.0000 known=(58579 @ 2.3306) novel=(70982 @ 2.2511) truthSites(18665 accessible, 18598 called), name=anonymous]
20:55:27.681 INFO  TrancheManager -   VQSLODTranche threshold -2.00 => selection metric threshold 1.020
20:55:27.693 INFO  TrancheManager -   Found tranche for -2.000: 1.020 threshold starting with variant 1099; running score is 0.001 
20:55:27.693 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-2.0000 known=(59019 @ 2.3111) novel=(71703 @ 2.2372) truthSites(18665 accessible, 18640 called), name=anonymous]
20:55:27.693 INFO  TrancheManager -   VQSLODTranche threshold -4.00 => selection metric threshold 1.040
20:55:27.703 INFO  TrancheManager -   Found tranche for -4.000: 1.040 threshold starting with variant 606; running score is 0.001 
20:55:27.703 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-4.0000 known=(59205 @ 2.3054) novel=(72010 @ 2.2272) truthSites(18665 accessible, 18648 called), name=anonymous]
20:55:27.703 INFO  TrancheManager -   VQSLODTranche threshold -6.00 => selection metric threshold 1.060
20:55:27.712 INFO  TrancheManager -   Found tranche for -6.000: 1.060 threshold starting with variant 429; running score is 0.001 
20:55:27.713 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-6.0000 known=(59292 @ 2.3026) novel=(72100 @ 2.2261) truthSites(18665 accessible, 18653 called), name=anonymous]
20:55:27.713 INFO  TrancheManager -   VQSLODTranche threshold -8.00 => selection metric threshold 1.080
20:55:27.722 INFO  TrancheManager -   Found tranche for -8.000: 1.080 threshold starting with variant 314; running score is 0.000 
20:55:27.722 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-8.0000 known=(59355 @ 2.3009) novel=(72152 @ 2.2247) truthSites(18665 accessible, 18657 called), name=anonymous]
20:55:27.722 INFO  TrancheManager -   VQSLODTranche threshold -10.00 => selection metric threshold 1.100
20:55:27.730 INFO  TrancheManager -   Found tranche for -10.000: 1.100 threshold starting with variant 264; running score is 0.000 
20:55:27.730 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-10.0000 known=(59372 @ 2.3008) novel=(72185 @ 2.2246) truthSites(18665 accessible, 18658 called), name=anonymous]
20:55:27.730 INFO  TrancheManager -   VQSLODTranche threshold -12.00 => selection metric threshold 1.120
20:55:27.744 INFO  TrancheManager -   Found tranche for -12.000: 1.120 threshold starting with variant 211; running score is 0.000 
20:55:27.744 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-12.0000 known=(59394 @ 2.3004) novel=(72216 @ 2.2244) truthSites(18665 accessible, 18659 called), name=anonymous]
20:55:27.744 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:28.055 INFO  VariantRecalibrator - Tranches plot will not be generated since we are running in scattered mode
20:55:28.061 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:28 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1103101952
20:55:28.087 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 12, 2025 at 8:55:29 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1103101952
20:55:29.621 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:29.621 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:29.621 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:29.621 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:29.621 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:29.621 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:29 PM UTC
20:55:29.621 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:29.621 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:29.621 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:29.621 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:29.621 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:29.621 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:29.621 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:29.621 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:29.621 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:29.621 INFO  VariantRecalibrator - Requester pays: disabled
20:55:29.621 INFO  VariantRecalibrator - Initializing engine
20:55:29.623 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:29.640 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:29.703 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
20:55:29.723 INFO  VariantRecalibrator - Done initializing engine
20:55:29.723 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:29.745 INFO  ProgressMeter - Starting traversal
20:55:29.746 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:29.834 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1902954.5
20:55:29.834 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
20:55:29.834 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
20:55:29.834 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
20:55:29.835 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
20:55:29.835 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
20:55:29.835 INFO  VariantDataManager - AS_FS: 	 mean = 1.08	 standard deviation = 2.43
20:55:29.835 INFO  VariantDataManager - AS_MQRankSum: 	 mean = 0.00	 standard deviation = 0.01
20:55:29.836 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR, AS_FS, AS_MQRankSum]
20:55:29.836 INFO  VariantDataManager - Training with 2769 variants after standard deviation thresholding.
20:55:29.836 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:29.891 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:29.933 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.56007
20:55:29.970 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.67355
20:55:29.995 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 5.08559
20:55:30.020 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.01567
20:55:30.045 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.02021
20:55:30.071 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01989
20:55:30.096 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02504
20:55:30.121 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03657
20:55:30.147 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.04057
20:55:30.172 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.08648
20:55:30.197 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.01514
20:55:30.223 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00496
20:55:30.248 INFO  VariantRecalibratorEngine - Finished iteration 65. 	Current change in mixture coefficients = 0.00163
20:55:30.248 INFO  VariantRecalibratorEngine - Convergence after 65 iterations!
20:55:30.251 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
20:55:30.270 INFO  VariantDataManager - Selected worst 5 scoring variants --> variants with LOD <= -5.0000.
20:55:30.270 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:30.270 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:30.270 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
20:55:30.270 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
20:55:30.284 INFO  TrancheManager - Finding 4 tranches for 2786 variants
20:55:30.284 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
20:55:30.285 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
20:55:30.285 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]
20:55:30.285 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
20:55:30.285 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
20:55:30.285 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]
20:55:30.285 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
20:55:30.285 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
20:55:30.285 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]
20:55:30.285 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
20:55:30.286 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
20:55:30.286 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]
20:55:30.286 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:30.308 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:30 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1103101952
20:55:30.310 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 12, 2025 at 8:55:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1103101952
[June 12, 2025 at 8:55:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1103101952
[June 12, 2025 at 8:55:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1103101952
[June 12, 2025 at 8:55:33 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1103101952
[June 12, 2025 at 8:55:33 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1103101952
[June 12, 2025 at 8:55:35 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1103101952
20:55:35.543 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:35.543 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:35.543 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:35.543 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:35.544 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:35.544 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:35 PM UTC
20:55:35.544 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:35.544 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:35.544 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:35.544 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:35.544 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:35.545 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:35.545 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:35.545 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:35.545 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:35.545 INFO  VariantRecalibrator - Requester pays: disabled
20:55:35.545 INFO  VariantRecalibrator - Initializing engine
20:55:35.546 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/dbsnp_132_b37.leftAligned.20.1M-10M.vcf
20:55:35.549 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/sites_r27_nr.b37_fwd.20.1M-10M.vcf
20:55:35.551 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/Omni25_sites_1525_samples.b37.20.1M-10M.vcf
20:55:35.553 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
20:55:35.556 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
20:55:35.557 INFO  VariantRecalibrator - Done initializing engine
20:55:35.557 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
20:55:35.557 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:35.557 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
20:55:35.558 INFO  ProgressMeter - Starting traversal
20:55:35.558 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:36.522 INFO  ProgressMeter -           20:9944766              0.0                131821        8204626.6
20:55:36.522 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
20:55:36.525 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
20:55:36.531 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
20:55:36.537 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
20:55:36.573 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
20:55:36.575 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
20:55:36.575 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:36.821 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:36.927 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
20:55:37.032 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
20:55:37.135 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
20:55:37.243 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
20:55:37.351 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
20:55:37.458 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
20:55:37.564 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
20:55:37.676 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
20:55:37.785 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
20:55:37.892 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
20:55:37.964 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
20:55:37.970 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:38.043 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
20:55:38.043 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:38.045 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:38.046 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
20:55:38.047 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
20:55:38.233 INFO  TrancheManager - Finding 12 tranches for 131821 variants
20:55:38.271 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
20:55:38.280 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
20:55:38.281 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]
20:55:38.281 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
20:55:38.290 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 381; running score is 0.001 
20:55:38.291 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]
20:55:38.291 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
20:55:38.309 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
20:55:38.309 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]
20:55:38.309 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
20:55:38.321 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 1480; running score is 0.002 
20:55:38.321 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]
20:55:38.321 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
20:55:38.333 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 2377; running score is 0.004 
20:55:38.333 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]
20:55:38.333 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
20:55:38.342 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 3042; running score is 0.005 
20:55:38.343 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]
20:55:38.343 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
20:55:38.352 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 3577; running score is 0.006 
20:55:38.352 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]
20:55:38.352 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
20:55:38.360 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 4004; running score is 0.007 
20:55:38.360 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]
20:55:38.360 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
20:55:38.373 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
20:55:38.374 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]
20:55:38.374 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
20:55:38.383 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 10673; running score is 0.020 
20:55:38.383 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]
20:55:38.383 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
20:55:38.393 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 16985; running score is 0.030 
20:55:38.393 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]
20:55:38.393 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
20:55:38.404 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
20:55:38.404 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]
20:55:38.404 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:38.712 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:38 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1103101952
20:55:38.735 INFO  gatk - Initializing VQSR tests/resetting random number generator
20:55:38.743 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:38.743 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
20:55:38.743 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
20:55:38.743 INFO  VariantRecalibrator - Executing as runner@pkrvmxyh4eaekms on Linux v6.11.0-1015-azure amd64
20:55:38.743 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
20:55:38.743 INFO  VariantRecalibrator - Start Date/Time: June 12, 2025 at 8:55:38 PM UTC
20:55:38.743 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:38.743 INFO  VariantRecalibrator - ------------------------------------------------------------
20:55:38.743 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
20:55:38.743 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
20:55:38.743 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
20:55:38.743 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
20:55:38.743 INFO  VariantRecalibrator - Deflater: IntelDeflater
20:55:38.743 INFO  VariantRecalibrator - Inflater: IntelInflater
20:55:38.743 INFO  VariantRecalibrator - GCS max retries/reopens: 20
20:55:38.743 INFO  VariantRecalibrator - Requester pays: disabled
20:55:38.743 INFO  VariantRecalibrator - Initializing engine
20:55:38.745 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:38.756 INFO  FeatureManager - Using codec VCFCodec to read file file:///home/runner/work/gatk/gatk/src/test/resources/large/VQSR/chr1snippet.doctoredMQ.sites_only.vcf.gz
20:55:38.790 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
20:55:38.807 INFO  VariantRecalibrator - Done initializing engine
20:55:38.808 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
20:55:38.818 INFO  ProgressMeter - Starting traversal
20:55:38.818 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
20:55:38.870 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3220384.6
20:55:38.870 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
20:55:38.870 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
20:55:38.870 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
20:55:38.870 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
20:55:38.870 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
20:55:38.871 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
20:55:38.871 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
20:55:38.871 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:38.903 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:38.919 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
20:55:38.934 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
20:55:38.950 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
20:55:38.966 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
20:55:38.982 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
20:55:38.998 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
20:55:39.013 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
20:55:39.029 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
20:55:39.045 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
20:55:39.061 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
20:55:39.077 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
20:55:39.092 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
20:55:39.092 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
20:55:39.094 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
20:55:39.102 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
20:55:39.103 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
20:55:39.103 INFO  VariantRecalibratorEngine - Finished iteration 0.
20:55:39.103 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
20:55:39.103 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
20:55:39.111 INFO  TrancheManager - Finding 12 tranches for 2786 variants
20:55:39.111 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
20:55:39.111 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
20:55:39.112 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]
20:55:39.112 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
20:55:39.112 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 2; running score is 0.001 
20:55:39.112 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]
20:55:39.112 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
20:55:39.112 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
20:55:39.112 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]
20:55:39.112 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
20:55:39.112 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 6; running score is 0.002 
20:55:39.112 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]
20:55:39.112 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
20:55:39.113 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 12; running score is 0.004 
20:55:39.113 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]
20:55:39.113 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
20:55:39.113 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 14; running score is 0.005 
20:55:39.113 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]
20:55:39.113 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
20:55:39.113 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 17; running score is 0.006 
20:55:39.113 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]
20:55:39.113 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
20:55:39.113 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 20; running score is 0.007 
20:55:39.113 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]
20:55:39.113 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
20:55:39.113 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
20:55:39.113 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]
20:55:39.113 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
20:55:39.114 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 56; running score is 0.020 
20:55:39.114 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]
20:55:39.114 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
20:55:39.114 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 84; running score is 0.030 
20:55:39.114 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]
20:55:39.114 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
20:55:39.114 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
20:55:39.114 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]
20:55:39.114 INFO  VariantRecalibrator - Writing out recalibration table...
20:55:39.127 INFO  VariantRecalibrator - Shutting down engine
[June 12, 2025 at 8:55:39 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1103101952
[June 12, 2025 at 8:56:47 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1616904192