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

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

tests
0

failures
0

ignored
34.613s

duration
100%

successful

Tests

Test Duration Result
testAnnotationsWithNoVarianceSpecified 0.694s passed
testBothAggregateRecalMode 5.241s passed
testBothRecalMode 2.467s passed
testInGatkLiteDocker 0.087s passed
testNoNegativeTrainingData 0.662s passed
testVQSRAnnotationOrder 0.212s passed
testVariantRecalibratorIndel 0.834s passed
testVariantRecalibratorModelInput 1.306s passed
testVariantRecalibratorRScriptOutput 1.626s passed
testVariantRecalibratorSNPAlternateTranches[0]([Ljava.lang.String;@7066363, /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.464s passed
testVariantRecalibratorSNPAlternateTranches[1]([Ljava.lang.String;@307e4c44, /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.402s passed
testVariantRecalibratorSNPMaxAttempts[0]([Ljava.lang.String;@604d23fa) 5.938s passed
testVariantRecalibratorSNP[0]([Ljava.lang.String;@52226e57, /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.320s passed
testVariantRecalibratorSNP[1]([Ljava.lang.String;@7066363, /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.083s passed
testVariantRecalibratorSNP[2]([Ljava.lang.String;@307e4c44, /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.472s passed
testVariantRecalibratorSNPscattered[0]([Ljava.lang.String;@2d5a1588) 3.274s passed
testVariantRecalibratorSampling 1.531s passed

Standard output

--------------------------------------------------------------------------------
[14:31:05] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[14:31:27] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorSampling/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[14:31:29] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[14:31:31] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[14:31:31] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[14:31:32] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[14:31:32] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorIndel/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/combined.phase1.chr20.raw.indels.filtered.sites.1M-10M.vcf
--------------------------------------------------------------------------------
[14:31:32] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[14:32:49] 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 2, 2025 at 2:31:10 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.08 minutes.
Runtime.totalMemory()=752877568
14:31:10.419 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:10.419 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:10.420 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:10.420 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:10.420 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:10.421 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:10 PM UTC
14:31:10.421 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:10.421 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:10.421 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:10.421 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:10.421 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:10.421 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:10.422 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:10.422 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:10.422 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:10.422 INFO  VariantRecalibrator - Requester pays: disabled
14:31:10.422 INFO  VariantRecalibrator - Initializing engine
14:31:10.428 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
14:31:10.456 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
14:31:10.551 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
14:31:10.586 INFO  VariantRecalibrator - Done initializing engine
14:31:10.587 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:10.622 INFO  ProgressMeter - Starting traversal
14:31:10.623 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:10.765 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1179295.8
14:31:10.765 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
14:31:10.765 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
14:31:10.766 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
14:31:10.767 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
14:31:10.767 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
14:31:10.776 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
14:31:10.777 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
14:31:10.777 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:10.831 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:10.854 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.16919
14:31:10.871 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.14268
14:31:10.890 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.19617
14:31:10.907 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.09047
14:31:10.926 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.05235
14:31:10.942 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04028
14:31:10.959 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02103
14:31:10.975 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01461
14:31:10.991 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01136
14:31:11.008 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00583
14:31:11.024 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00291
14:31:11.034 INFO  VariantRecalibratorEngine - Convergence after 58 iterations!
14:31:11.039 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
14:31:11.049 INFO  VariantDataManager - Selected worst 0 scoring variants --> variants with LOD <= -5.5000.
14:31:11.057 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:11 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=752877568
14:31:11.062 INFO  gatk - Initializing VQSR tests/resetting random number generator
14:31:11.079 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:11.079 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:11.079 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:11.080 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:11.080 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:11.080 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:11 PM UTC
14:31:11.080 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:11.080 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:11.080 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:11.080 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:11.080 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:11.080 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:11.081 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:11.081 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:11.081 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:11.081 INFO  VariantRecalibrator - Requester pays: disabled
14:31:11.081 INFO  VariantRecalibrator - Initializing engine
14:31:11.083 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
14:31:11.086 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
14:31:11.089 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
14:31:11.091 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
14:31:11.095 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
14:31:11.096 INFO  VariantRecalibrator - Done initializing engine
14:31:11.098 WARN  VariantDataManager - Ignoring duplicate annotations for recalibration [HRun]
14:31:11.098 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
14:31:11.099 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:11.099 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
14:31:11.101 INFO  ProgressMeter - Starting traversal
14:31:11.101 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:12.154 INFO  ProgressMeter -           20:9944766              0.0                131821        7518308.0
14:31:12.154 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
14:31:12.161 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
14:31:12.168 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
14:31:12.176 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
14:31:12.204 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
14:31:12.211 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
14:31:12.211 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:12.531 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:12.615 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
14:31:12.699 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
14:31:12.784 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
14:31:12.871 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
14:31:12.961 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
14:31:13.048 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
14:31:13.138 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
14:31:13.227 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
14:31:13.329 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
14:31:13.419 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
14:31:13.491 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
14:31:13.507 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:13.579 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
14:31:13.579 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:13.582 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:13.582 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
14:31:13.585 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:13.772 INFO  TrancheManager - Finding 4 tranches for 131821 variants
14:31:13.813 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
14:31:13.829 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
14:31:13.829 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]
14:31:13.830 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
14:31:13.845 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
14:31:13.846 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]
14:31:13.846 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
14:31:13.861 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
14:31:13.862 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]
14:31:13.862 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
14:31:13.877 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
14:31:13.877 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]
14:31:13.878 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:14.346 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:14 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=962592768
14:31:14.383 INFO  gatk - Initializing VQSR tests/resetting random number generator
14:31:14.399 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:14.399 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:14.399 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:14.399 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:14.399 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:14.400 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:14 PM UTC
14:31:14.400 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:14.400 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:14.400 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:14.400 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:14.400 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:14.400 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:14.400 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:14.400 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:14.400 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:14.400 INFO  VariantRecalibrator - Requester pays: disabled
14:31:14.400 INFO  VariantRecalibrator - Initializing engine
14:31:14.402 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
14:31:14.405 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
14:31:14.407 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
14:31:14.412 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
14:31:14.416 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
14:31:14.417 INFO  VariantRecalibrator - Done initializing engine
14:31:14.417 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
14:31:14.417 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:14.417 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
14:31:14.419 INFO  ProgressMeter - Starting traversal
14:31:14.419 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:15.367 INFO  ProgressMeter -           20:9944766              0.0                131821        8351911.3
14:31:15.367 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
14:31:15.370 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
14:31:15.375 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
14:31:15.379 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
14:31:15.406 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
14:31:15.408 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
14:31:15.408 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:15.678 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:15.801 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
14:31:15.933 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
14:31:16.025 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
14:31:16.119 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
14:31:16.208 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
14:31:16.296 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
14:31:16.386 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
14:31:16.477 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
14:31:16.568 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
14:31:16.659 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
14:31:16.731 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
14:31:16.738 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:16.820 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
14:31:16.820 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:16.821 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:16.822 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
14:31:16.824 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:17.010 INFO  TrancheManager - Finding 4 tranches for 131821 variants
14:31:17.049 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
14:31:17.063 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
14:31:17.063 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]
14:31:17.063 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
14:31:17.077 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
14:31:17.077 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]
14:31:17.077 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
14:31:17.092 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
14:31:17.092 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]
14:31:17.093 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
14:31:17.108 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
14:31:17.108 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]
14:31:17.109 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:17.443 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:17 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1084227584
14:31:17.467 INFO  gatk - Initializing VQSR tests/resetting random number generator
14:31:17.481 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:17.482 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:17.482 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:17.482 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:17.482 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:17.482 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:17 PM UTC
14:31:17.482 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:17.482 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:17.482 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:17.483 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:17.483 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:17.483 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:17.483 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:17.483 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:17.483 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:17.483 INFO  VariantRecalibrator - Requester pays: disabled
14:31:17.483 INFO  VariantRecalibrator - Initializing engine
14:31:17.485 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
14:31:17.497 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
14:31:17.540 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
14:31:17.560 INFO  VariantRecalibrator - Done initializing engine
14:31:17.561 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:17.577 INFO  ProgressMeter - Starting traversal
14:31:17.577 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:17.638 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        2745245.9
14:31:17.638 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
14:31:17.639 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
14:31:17.639 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
14:31:17.639 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
14:31:17.639 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
14:31:17.640 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
14:31:17.640 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
14:31:17.640 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:17.671 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:17.687 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
14:31:17.705 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
14:31:17.721 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
14:31:17.738 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
14:31:17.755 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
14:31:17.772 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
14:31:17.789 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
14:31:17.807 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
14:31:17.829 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
14:31:17.845 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
14:31:17.861 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
14:31:17.877 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
14:31:17.877 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
14:31:17.878 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
14:31:17.888 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
14:31:17.889 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:17.889 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:17.889 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
14:31:17.889 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
14:31:17.902 INFO  TrancheManager - Finding 4 tranches for 2786 variants
14:31:17.904 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
14:31:17.904 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
14:31:17.905 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]
14:31:17.905 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
14:31:17.905 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
14:31:17.905 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]
14:31:17.905 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
14:31:17.905 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
14:31:17.905 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]
14:31:17.906 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
14:31:17.906 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
14:31:17.906 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]
14:31:17.906 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:17.936 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:17 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1084227584
14:31:17.942 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 2, 2025 at 2:31:20 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1084227584
14:31:20.774 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:20.774 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:20.774 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:20.774 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:20.774 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:20.774 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:20 PM UTC
14:31:20.775 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:20.775 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:20.775 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:20.775 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:20.775 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:20.775 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:20.775 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:20.775 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:20.775 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:20.775 INFO  VariantRecalibrator - Requester pays: disabled
14:31:20.775 INFO  VariantRecalibrator - Initializing engine
14:31:20.776 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
14:31:20.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
14:31:20.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
14:31:20.784 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
14:31:20.786 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
14:31:20.810 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
14:31:20.811 INFO  VariantRecalibrator - Done initializing engine
14:31:20.812 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
14:31:20.812 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:20.812 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
14:31:20.815 INFO  ProgressMeter - Starting traversal
14:31:20.816 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:21.874 INFO  ProgressMeter -           20:9938789              0.0                134919        7651361.1
14:31:21.874 INFO  ProgressMeter - Traversal complete. Processed 134919 total variants in 0.0 minutes.
14:31:21.877 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
14:31:21.882 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
14:31:21.886 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
14:31:21.913 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
14:31:21.915 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
14:31:21.915 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:22.137 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:22.253 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.13181
14:31:22.359 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.46782
14:31:22.470 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 9.04961
14:31:22.574 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.04477
14:31:22.642 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01711
14:31:22.710 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.02053
14:31:22.778 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.01194
14:31:22.846 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01038
14:31:22.914 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.06192
14:31:22.983 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01281
14:31:23.054 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00457
14:31:23.082 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
14:31:23.088 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
14:31:23.211 INFO  VariantDataManager - Selected worst 754 scoring variants --> variants with LOD <= -5.0000.
14:31:23.211 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:23.213 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:23.215 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.05287
14:31:23.216 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.02030
14:31:23.217 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.00986
14:31:23.219 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.00749
14:31:23.220 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.00850
14:31:23.221 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01430
14:31:23.222 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02541
14:31:23.223 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.02173
14:31:23.224 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01024
14:31:23.226 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00479
14:31:23.227 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00245
14:31:23.227 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
14:31:23.229 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
14:31:23.429 INFO  TrancheManager - Finding 4 tranches for 134603 variants
14:31:23.482 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
14:31:23.497 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
14:31:23.497 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]
14:31:23.497 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
14:31:23.512 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 649; running score is 0.001 
14:31:23.512 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]
14:31:23.512 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
14:31:23.528 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 7924; running score is 0.010 
14:31:23.528 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]
14:31:23.528 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
14:31:23.544 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 52632; running score is 0.100 
14:31:23.544 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]
14:31:23.544 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:23.880 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:23 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1084227584
14:31:23.882 INFO  gatk - Initializing VQSR tests/resetting random number generator
14:31:23.890 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:23.890 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:23.890 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:23.891 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:23.891 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:23.891 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:23 PM UTC
14:31:23.891 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:23.891 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:23.891 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:23.891 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:23.891 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:23.891 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:23.891 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:23.891 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:23.891 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:23.891 INFO  VariantRecalibrator - Requester pays: disabled
14:31:23.892 INFO  VariantRecalibrator - Initializing engine
14:31:23.893 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
14:31:23.895 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
14:31:23.896 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
14:31:23.898 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
14:31:23.900 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
14:31:23.901 INFO  VariantRecalibrator - Done initializing engine
14:31:23.901 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
14:31:23.902 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:23.902 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
14:31:23.903 INFO  ProgressMeter - Starting traversal
14:31:23.903 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:24.849 INFO  ProgressMeter -           20:9944766              0.0                131821        8360740.0
14:31:24.849 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
14:31:24.852 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
14:31:24.856 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
14:31:24.860 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
14:31:24.885 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
14:31:24.887 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
14:31:24.887 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:25.158 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:25.273 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
14:31:25.392 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
14:31:25.523 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
14:31:25.653 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
14:31:25.759 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
14:31:25.847 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
14:31:25.938 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
14:31:26.030 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
14:31:26.121 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
14:31:26.211 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
14:31:26.283 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
14:31:26.290 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:26.360 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
14:31:26.360 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:26.361 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:26.362 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
14:31:26.364 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:26.545 INFO  TrancheManager - Finding 12 tranches for 131821 variants
14:31:26.591 INFO  TrancheManager -   VQSLODTranche threshold 10.00 => selection metric threshold 0.900
14:31:26.617 INFO  TrancheManager -   Found tranche for 10.000: 0.900 threshold starting with variant 97819; running score is 0.262 
14:31:26.617 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=10.0000 known=(29048 @ 2.5026) novel=(4954 @ 2.3633) truthSites(18665 accessible, 13780 called), name=anonymous]
14:31:26.617 INFO  TrancheManager -   VQSLODTranche threshold 8.00 => selection metric threshold 0.920
14:31:26.635 INFO  TrancheManager -   Found tranche for 8.000: 0.920 threshold starting with variant 68875; running score is 0.114 
14:31:26.635 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=8.0000 known=(44004 @ 2.4829) novel=(18942 @ 2.4147) truthSites(18665 accessible, 16543 called), name=anonymous]
14:31:26.636 INFO  TrancheManager -   VQSLODTranche threshold 6.00 => selection metric threshold 0.940
14:31:26.652 INFO  TrancheManager -   Found tranche for 6.000: 0.940 threshold starting with variant 34094; running score is 0.052 
14:31:26.652 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=6.0000 known=(52474 @ 2.4242) novel=(45253 @ 2.3994) truthSites(18665 accessible, 17701 called), name=anonymous]
14:31:26.652 INFO  TrancheManager -   VQSLODTranche threshold 4.00 => selection metric threshold 0.960
14:31:26.669 INFO  TrancheManager -   Found tranche for 4.000: 0.960 threshold starting with variant 12275; running score is 0.023 
14:31:26.669 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=4.0000 known=(56181 @ 2.3913) novel=(63365 @ 2.3212) truthSites(18665 accessible, 18243 called), name=anonymous]
14:31:26.669 INFO  TrancheManager -   VQSLODTranche threshold 2.00 => selection metric threshold 0.980
14:31:26.685 INFO  TrancheManager -   Found tranche for 2.000: 0.980 threshold starting with variant 4952; running score is 0.009 
14:31:26.685 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=2.0000 known=(57758 @ 2.3573) novel=(69111 @ 2.2722) truthSites(18665 accessible, 18502 called), name=anonymous]
14:31:26.685 INFO  TrancheManager -   VQSLODTranche threshold 0.00 => selection metric threshold 1.000
14:31:26.701 INFO  TrancheManager -   Found tranche for 0.000: 1.000 threshold starting with variant 2260; running score is 0.004 
14:31:26.701 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=0.0000 known=(58579 @ 2.3306) novel=(70982 @ 2.2511) truthSites(18665 accessible, 18598 called), name=anonymous]
14:31:26.701 INFO  TrancheManager -   VQSLODTranche threshold -2.00 => selection metric threshold 1.020
14:31:26.716 INFO  TrancheManager -   Found tranche for -2.000: 1.020 threshold starting with variant 1099; running score is 0.001 
14:31:26.716 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-2.0000 known=(59019 @ 2.3111) novel=(71703 @ 2.2372) truthSites(18665 accessible, 18640 called), name=anonymous]
14:31:26.717 INFO  TrancheManager -   VQSLODTranche threshold -4.00 => selection metric threshold 1.040
14:31:26.732 INFO  TrancheManager -   Found tranche for -4.000: 1.040 threshold starting with variant 606; running score is 0.001 
14:31:26.732 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-4.0000 known=(59205 @ 2.3054) novel=(72010 @ 2.2272) truthSites(18665 accessible, 18648 called), name=anonymous]
14:31:26.732 INFO  TrancheManager -   VQSLODTranche threshold -6.00 => selection metric threshold 1.060
14:31:26.749 INFO  TrancheManager -   Found tranche for -6.000: 1.060 threshold starting with variant 429; running score is 0.001 
14:31:26.749 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-6.0000 known=(59292 @ 2.3026) novel=(72100 @ 2.2261) truthSites(18665 accessible, 18653 called), name=anonymous]
14:31:26.749 INFO  TrancheManager -   VQSLODTranche threshold -8.00 => selection metric threshold 1.080
14:31:26.764 INFO  TrancheManager -   Found tranche for -8.000: 1.080 threshold starting with variant 314; running score is 0.000 
14:31:26.764 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-8.0000 known=(59355 @ 2.3009) novel=(72152 @ 2.2247) truthSites(18665 accessible, 18657 called), name=anonymous]
14:31:26.764 INFO  TrancheManager -   VQSLODTranche threshold -10.00 => selection metric threshold 1.100
14:31:26.779 INFO  TrancheManager -   Found tranche for -10.000: 1.100 threshold starting with variant 264; running score is 0.000 
14:31:26.779 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-10.0000 known=(59372 @ 2.3008) novel=(72185 @ 2.2246) truthSites(18665 accessible, 18658 called), name=anonymous]
14:31:26.779 INFO  TrancheManager -   VQSLODTranche threshold -12.00 => selection metric threshold 1.120
14:31:26.794 INFO  TrancheManager -   Found tranche for -12.000: 1.120 threshold starting with variant 211; running score is 0.000 
14:31:26.794 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-12.0000 known=(59394 @ 2.3004) novel=(72216 @ 2.2244) truthSites(18665 accessible, 18659 called), name=anonymous]
14:31:26.795 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:27.124 INFO  VariantRecalibrator - Tranches plot will not be generated since we are running in scattered mode
14:31:27.130 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:27 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1084227584
14:31:27.156 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 2, 2025 at 2:31:28 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1084227584
14:31:28.701 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:28.702 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:28.702 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:28.702 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:28.702 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:28.702 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:28 PM UTC
14:31:28.702 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:28.702 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:28.702 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:28.702 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:28.702 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:28.702 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:28.702 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:28.702 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:28.703 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:28.703 INFO  VariantRecalibrator - Requester pays: disabled
14:31:28.703 INFO  VariantRecalibrator - Initializing engine
14:31:28.704 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
14:31:28.721 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
14:31:28.788 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
14:31:28.816 INFO  VariantRecalibrator - Done initializing engine
14:31:28.816 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:28.838 INFO  ProgressMeter - Starting traversal
14:31:28.838 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:28.939 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1658019.8
14:31:28.939 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
14:31:28.939 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
14:31:28.940 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
14:31:28.940 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
14:31:28.940 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
14:31:28.940 INFO  VariantDataManager - AS_FS: 	 mean = 1.08	 standard deviation = 2.43
14:31:28.940 INFO  VariantDataManager - AS_MQRankSum: 	 mean = 0.00	 standard deviation = 0.01
14:31:28.941 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR, AS_FS, AS_MQRankSum]
14:31:28.942 INFO  VariantDataManager - Training with 2769 variants after standard deviation thresholding.
14:31:28.942 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:28.997 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:29.027 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.56007
14:31:29.052 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.67355
14:31:29.077 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 5.08559
14:31:29.102 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.01567
14:31:29.127 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.02021
14:31:29.152 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01989
14:31:29.177 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02504
14:31:29.202 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03657
14:31:29.227 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.04057
14:31:29.252 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.08648
14:31:29.277 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.01514
14:31:29.303 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00496
14:31:29.328 INFO  VariantRecalibratorEngine - Finished iteration 65. 	Current change in mixture coefficients = 0.00163
14:31:29.328 INFO  VariantRecalibratorEngine - Convergence after 65 iterations!
14:31:29.330 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
14:31:29.349 INFO  VariantDataManager - Selected worst 5 scoring variants --> variants with LOD <= -5.0000.
14:31:29.349 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:29.349 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:29.349 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
14:31:29.349 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
14:31:29.363 INFO  TrancheManager - Finding 4 tranches for 2786 variants
14:31:29.364 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
14:31:29.364 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
14:31:29.364 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]
14:31:29.364 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
14:31:29.364 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
14:31:29.364 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]
14:31:29.364 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
14:31:29.365 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
14:31:29.365 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]
14:31:29.365 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
14:31:29.365 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
14:31:29.365 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]
14:31:29.365 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:29.382 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:29 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1084227584
14:31:29.384 INFO  gatk - Initializing VQSR tests/resetting random number generator
[June 2, 2025 at 2:31:31 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1084227584
[June 2, 2025 at 2:31:31 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1084227584
[June 2, 2025 at 2:31:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1084227584
[June 2, 2025 at 2:31:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1084227584
[June 2, 2025 at 2:31:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1084227584
[June 2, 2025 at 2:31:34 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.03 minutes.
Runtime.totalMemory()=1084227584
14:31:34.630 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:34.630 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:34.630 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:34.631 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:34.631 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:34.631 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:34 PM UTC
14:31:34.631 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:34.631 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:34.631 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:34.631 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:34.631 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:34.631 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:34.631 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:34.631 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:34.631 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:34.631 INFO  VariantRecalibrator - Requester pays: disabled
14:31:34.631 INFO  VariantRecalibrator - Initializing engine
14:31:34.632 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
14:31:34.635 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
14:31:34.636 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
14:31:34.638 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
14:31:34.641 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
14:31:34.642 INFO  VariantRecalibrator - Done initializing engine
14:31:34.642 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
14:31:34.642 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:34.642 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
14:31:34.643 INFO  ProgressMeter - Starting traversal
14:31:34.643 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:35.602 INFO  ProgressMeter -           20:9944766              0.0                131821        8247403.5
14:31:35.602 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
14:31:35.605 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
14:31:35.609 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
14:31:35.612 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
14:31:35.634 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
14:31:35.635 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
14:31:35.636 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:35.906 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:36.029 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
14:31:36.163 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
14:31:36.294 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
14:31:36.426 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
14:31:36.558 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
14:31:36.683 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
14:31:36.816 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
14:31:36.953 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
14:31:37.069 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
14:31:37.160 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
14:31:37.233 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
14:31:37.240 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:37.313 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
14:31:37.313 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:37.314 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:37.315 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
14:31:37.317 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
14:31:37.502 INFO  TrancheManager - Finding 12 tranches for 131821 variants
14:31:37.544 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
14:31:37.559 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
14:31:37.559 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]
14:31:37.559 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
14:31:37.574 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 381; running score is 0.001 
14:31:37.574 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]
14:31:37.574 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
14:31:37.595 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
14:31:37.596 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]
14:31:37.596 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
14:31:37.612 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 1480; running score is 0.002 
14:31:37.612 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]
14:31:37.612 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
14:31:37.627 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 2377; running score is 0.004 
14:31:37.627 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]
14:31:37.627 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
14:31:37.643 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 3042; running score is 0.005 
14:31:37.643 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]
14:31:37.643 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
14:31:37.658 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 3577; running score is 0.006 
14:31:37.658 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]
14:31:37.658 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
14:31:37.673 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 4004; running score is 0.007 
14:31:37.674 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]
14:31:37.674 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
14:31:37.691 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
14:31:37.691 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]
14:31:37.691 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
14:31:37.706 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 10673; running score is 0.020 
14:31:37.707 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]
14:31:37.707 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
14:31:37.727 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 16985; running score is 0.030 
14:31:37.727 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]
14:31:37.727 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
14:31:37.742 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
14:31:37.742 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]
14:31:37.742 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:38.060 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:38 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.06 minutes.
Runtime.totalMemory()=1084227584
14:31:38.083 INFO  gatk - Initializing VQSR tests/resetting random number generator
14:31:38.091 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:38.091 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
14:31:38.091 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
14:31:38.091 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
14:31:38.091 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
14:31:38.091 INFO  VariantRecalibrator - Start Date/Time: June 2, 2025 at 2:31:38 PM UTC
14:31:38.091 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:38.091 INFO  VariantRecalibrator - ------------------------------------------------------------
14:31:38.092 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
14:31:38.092 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
14:31:38.092 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
14:31:38.092 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
14:31:38.092 INFO  VariantRecalibrator - Deflater: IntelDeflater
14:31:38.092 INFO  VariantRecalibrator - Inflater: IntelInflater
14:31:38.092 INFO  VariantRecalibrator - GCS max retries/reopens: 20
14:31:38.092 INFO  VariantRecalibrator - Requester pays: disabled
14:31:38.092 INFO  VariantRecalibrator - Initializing engine
14:31:38.093 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
14:31:38.103 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
14:31:38.143 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
14:31:38.155 INFO  VariantRecalibrator - Done initializing engine
14:31:38.155 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
14:31:38.166 INFO  ProgressMeter - Starting traversal
14:31:38.166 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
14:31:38.216 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3417551.0
14:31:38.216 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
14:31:38.216 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
14:31:38.216 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
14:31:38.216 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
14:31:38.217 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
14:31:38.217 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
14:31:38.217 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
14:31:38.217 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:38.248 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:38.265 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
14:31:38.283 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
14:31:38.299 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
14:31:38.316 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
14:31:38.332 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
14:31:38.349 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
14:31:38.365 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
14:31:38.382 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
14:31:38.398 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
14:31:38.415 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
14:31:38.431 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
14:31:38.447 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
14:31:38.447 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
14:31:38.449 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
14:31:38.458 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
14:31:38.458 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
14:31:38.458 INFO  VariantRecalibratorEngine - Finished iteration 0.
14:31:38.458 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
14:31:38.458 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
14:31:38.466 INFO  TrancheManager - Finding 12 tranches for 2786 variants
14:31:38.467 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
14:31:38.467 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
14:31:38.467 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]
14:31:38.467 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
14:31:38.467 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 2; running score is 0.001 
14:31:38.467 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]
14:31:38.468 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
14:31:38.468 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
14:31:38.468 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]
14:31:38.468 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
14:31:38.468 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 6; running score is 0.002 
14:31:38.468 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]
14:31:38.468 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
14:31:38.468 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 12; running score is 0.004 
14:31:38.468 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]
14:31:38.468 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
14:31:38.468 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 14; running score is 0.005 
14:31:38.468 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]
14:31:38.468 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
14:31:38.469 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 17; running score is 0.006 
14:31:38.469 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]
14:31:38.469 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
14:31:38.469 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 20; running score is 0.007 
14:31:38.469 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]
14:31:38.469 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
14:31:38.469 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
14:31:38.469 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]
14:31:38.469 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
14:31:38.469 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 56; running score is 0.020 
14:31:38.469 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]
14:31:38.469 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
14:31:38.470 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 84; running score is 0.030 
14:31:38.470 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]
14:31:38.470 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
14:31:38.470 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
14:31:38.470 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]
14:31:38.470 INFO  VariantRecalibrator - Writing out recalibration table...
14:31:38.483 INFO  VariantRecalibrator - Shutting down engine
[June 2, 2025 at 2:31:38 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1084227584
[June 2, 2025 at 2:32:50 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=629145600