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

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

tests
0

failures
0

ignored
33.510s

duration
100%

successful

Tests

Test Duration Result
testAnnotationsWithNoVarianceSpecified 0.687s passed
testBothAggregateRecalMode 5.129s passed
testBothRecalMode 2.438s passed
testInGatkLiteDocker 0.084s passed
testNoNegativeTrainingData 0.509s passed
testVQSRAnnotationOrder 0.213s passed
testVariantRecalibratorIndel 0.920s passed
testVariantRecalibratorModelInput 1.256s passed
testVariantRecalibratorRScriptOutput 1.574s 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.050s 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.610s passed
testVariantRecalibratorSNP[0]([Ljava.lang.String;@3cc30dee, /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.377s 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.237s 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.501s passed
testVariantRecalibratorSNPscattered[0]([Ljava.lang.String;@2d5a1588) 3.083s passed
testVariantRecalibratorSampling 1.440s passed

Standard output

--------------------------------------------------------------------------------
[15:54:26] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[15:54:48] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorSampling/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[15:54:50] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[15:54:52] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[15:54:52] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[15:54:52] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[15:54:52] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorIndel/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/combined.phase1.chr20.raw.indels.filtered.sites.1M-10M.vcf
--------------------------------------------------------------------------------
[15:54:53] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[15:56:08] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf

Standard error

[May 27, 2025 at 3:54:31 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.08 minutes.
Runtime.totalMemory()=717225984
15:54:31.823 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:31.824 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:31.824 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:31.824 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:31.824 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:31.824 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:31 PM UTC
15:54:31.824 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:31.825 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:31.825 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:31.825 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:31.825 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:31.825 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:31.825 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:31.825 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:31.825 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:31.826 INFO  VariantRecalibrator - Requester pays: disabled
15:54:31.826 INFO  VariantRecalibrator - Initializing engine
15:54:31.828 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
15:54:31.844 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
15:54:31.909 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:54:31.928 INFO  VariantRecalibrator - Done initializing engine
15:54:31.929 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:31.955 INFO  ProgressMeter - Starting traversal
15:54:31.956 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:32.038 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        2042195.1
15:54:32.039 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:54:32.039 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:54:32.040 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:54:32.041 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:54:32.042 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:54:32.047 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
15:54:32.047 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
15:54:32.047 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:32.079 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:32.098 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.16919
15:54:32.116 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.14268
15:54:32.135 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.19617
15:54:32.153 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.09047
15:54:32.171 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.05235
15:54:32.189 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04028
15:54:32.208 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02103
15:54:32.226 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01461
15:54:32.244 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01136
15:54:32.262 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00583
15:54:32.282 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00291
15:54:32.293 INFO  VariantRecalibratorEngine - Convergence after 58 iterations!
15:54:32.295 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:54:32.305 INFO  VariantDataManager - Selected worst 0 scoring variants --> variants with LOD <= -5.5000.
15:54:32.312 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=717225984
15:54:32.315 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:54:32.331 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:32.331 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:32.331 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:32.331 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:32.332 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:32.332 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:32 PM UTC
15:54:32.332 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:32.332 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:32.332 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:32.332 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:32.332 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:32.332 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:32.332 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:32.333 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:32.333 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:32.333 INFO  VariantRecalibrator - Requester pays: disabled
15:54:32.333 INFO  VariantRecalibrator - Initializing engine
15:54:32.334 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
15:54:32.337 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
15:54:32.340 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
15:54:32.342 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
15:54:32.345 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:54:32.346 INFO  VariantRecalibrator - Done initializing engine
15:54:32.348 WARN  VariantDataManager - Ignoring duplicate annotations for recalibration [HRun]
15:54:32.348 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:54:32.349 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:32.349 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:54:32.351 INFO  ProgressMeter - Starting traversal
15:54:32.351 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:33.460 INFO  ProgressMeter -           20:9944766              0.0                131821        7131884.6
15:54:33.461 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:54:33.466 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:54:33.471 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:54:33.475 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:54:33.500 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:54:33.502 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:54:33.503 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:33.759 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:33.871 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:54:33.987 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:54:34.079 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:54:34.172 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:54:34.266 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:54:34.358 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:54:34.454 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:54:34.548 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:54:34.643 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:54:34.738 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:54:34.829 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:54:34.836 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:34.907 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:54:34.907 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:34.909 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:34.909 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:54:34.911 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:35.091 INFO  TrancheManager - Finding 4 tranches for 131821 variants
15:54:35.123 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:54:35.129 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:54:35.129 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]
15:54:35.129 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:54:35.136 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
15:54:35.136 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]
15:54:35.136 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:54:35.141 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
15:54:35.141 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]
15:54:35.142 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:54:35.149 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
15:54:35.150 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]
15:54:35.150 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:35.653 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:35 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.06 minutes.
Runtime.totalMemory()=1061158912
15:54:35.694 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:54:35.710 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:35.711 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:35.711 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:35.711 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:35.711 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:35.711 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:35 PM UTC
15:54:35.711 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:35.711 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:35.711 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:35.711 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:35.712 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:35.712 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:35.712 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:35.712 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:35.712 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:35.712 INFO  VariantRecalibrator - Requester pays: disabled
15:54:35.712 INFO  VariantRecalibrator - Initializing engine
15:54:35.714 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
15:54:35.716 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
15:54:35.718 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
15:54:35.723 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
15:54:35.727 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:54:35.728 INFO  VariantRecalibrator - Done initializing engine
15:54:35.728 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:54:35.728 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:35.728 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:54:35.730 INFO  ProgressMeter - Starting traversal
15:54:35.730 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:36.722 INFO  ProgressMeter -           20:9944766              0.0                131821        7973044.4
15:54:36.723 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:54:36.725 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:54:36.729 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:54:36.731 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:54:36.757 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:54:36.759 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:54:36.759 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:37.012 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:37.142 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:54:37.258 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:54:37.376 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:54:37.494 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:54:37.612 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:54:37.733 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:54:37.851 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:54:37.970 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:54:38.105 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:54:38.200 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:54:38.276 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:54:38.283 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:38.357 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:54:38.357 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:38.358 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:38.359 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:54:38.361 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:38.545 INFO  TrancheManager - Finding 4 tranches for 131821 variants
15:54:38.576 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:54:38.580 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:54:38.580 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]
15:54:38.580 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:54:38.585 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
15:54:38.585 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]
15:54:38.585 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:54:38.590 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
15:54:38.590 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]
15:54:38.590 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:54:38.596 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
15:54:38.596 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]
15:54:38.596 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:38.906 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:38 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1168113664
15:54:38.931 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:54:38.948 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:38.948 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:38.948 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:38.949 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:38.949 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:38.949 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:38 PM UTC
15:54:38.949 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:38.949 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:38.949 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:38.949 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:38.949 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:38.949 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:38.949 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:38.949 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:38.950 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:38.950 INFO  VariantRecalibrator - Requester pays: disabled
15:54:38.950 INFO  VariantRecalibrator - Initializing engine
15:54:38.951 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
15:54:38.971 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
15:54:39.019 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:54:39.036 INFO  VariantRecalibrator - Done initializing engine
15:54:39.036 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:39.052 INFO  ProgressMeter - Starting traversal
15:54:39.052 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:39.121 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        2426956.5
15:54:39.121 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:54:39.121 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:54:39.122 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:54:39.122 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:54:39.122 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:54:39.123 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
15:54:39.123 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
15:54:39.123 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:39.152 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:39.169 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
15:54:39.186 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
15:54:39.203 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
15:54:39.220 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
15:54:39.237 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
15:54:39.254 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
15:54:39.270 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
15:54:39.287 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
15:54:39.304 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
15:54:39.321 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
15:54:39.338 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
15:54:39.354 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
15:54:39.354 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
15:54:39.356 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:54:39.372 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
15:54:39.372 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:39.372 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:39.372 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:54:39.372 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:54:39.386 INFO  TrancheManager - Finding 4 tranches for 2786 variants
15:54:39.388 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:54:39.388 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:54:39.388 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]
15:54:39.388 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:54:39.389 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
15:54:39.389 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]
15:54:39.389 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:54:39.389 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
15:54:39.389 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]
15:54:39.389 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:54:39.390 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
15:54:39.390 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]
15:54:39.390 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:39.428 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:39 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1168113664
15:54:39.435 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 3:54:42 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1168113664
15:54:42.043 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:42.043 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:42.044 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:42.044 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:42.044 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:42.044 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:42 PM UTC
15:54:42.044 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:42.044 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:42.044 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:42.044 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:42.044 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:42.044 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:42.044 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:42.044 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:42.044 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:42.045 INFO  VariantRecalibrator - Requester pays: disabled
15:54:42.045 INFO  VariantRecalibrator - Initializing engine
15:54:42.046 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
15:54:42.049 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
15:54:42.050 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
15:54:42.053 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
15:54:42.055 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
15:54:42.078 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:54:42.079 INFO  VariantRecalibrator - Done initializing engine
15:54:42.080 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:54:42.080 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:42.080 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:54:42.083 INFO  ProgressMeter - Starting traversal
15:54:42.083 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:43.099 INFO  ProgressMeter -           20:9938789              0.0                134919        7975507.4
15:54:43.099 INFO  ProgressMeter - Traversal complete. Processed 134919 total variants in 0.0 minutes.
15:54:43.101 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:54:43.105 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:54:43.107 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:54:43.128 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:54:43.130 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:54:43.130 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:43.330 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:43.414 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.13181
15:54:43.500 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.46782
15:54:43.587 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 9.04961
15:54:43.677 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.04477
15:54:43.766 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01711
15:54:43.856 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.02053
15:54:43.945 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.01194
15:54:44.035 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01038
15:54:44.125 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.06192
15:54:44.216 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01281
15:54:44.292 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00457
15:54:44.322 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
15:54:44.327 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
15:54:44.451 INFO  VariantDataManager - Selected worst 754 scoring variants --> variants with LOD <= -5.0000.
15:54:44.451 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:44.453 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:44.455 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.05287
15:54:44.456 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.02030
15:54:44.458 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.00986
15:54:44.459 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.00749
15:54:44.460 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.00850
15:54:44.462 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01430
15:54:44.463 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02541
15:54:44.464 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.02173
15:54:44.466 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01024
15:54:44.467 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00479
15:54:44.468 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00245
15:54:44.469 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
15:54:44.471 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
15:54:44.667 INFO  TrancheManager - Finding 4 tranches for 134603 variants
15:54:44.708 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:54:44.712 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:54:44.713 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]
15:54:44.713 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:54:44.718 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 649; running score is 0.001 
15:54:44.718 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]
15:54:44.718 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:54:44.722 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 7924; running score is 0.010 
15:54:44.723 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]
15:54:44.723 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:54:44.727 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 52632; running score is 0.100 
15:54:44.727 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]
15:54:44.727 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:45.044 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:45 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1168113664
15:54:45.046 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:54:45.054 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:45.054 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:45.054 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:45.054 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:45.054 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:45.054 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:45 PM UTC
15:54:45.054 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:45.054 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:45.054 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:45.055 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:45.055 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:45.055 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:45.055 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:45.055 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:45.055 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:45.055 INFO  VariantRecalibrator - Requester pays: disabled
15:54:45.055 INFO  VariantRecalibrator - Initializing engine
15:54:45.056 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
15:54:45.058 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
15:54:45.059 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
15:54:45.060 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
15:54:45.062 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:54:45.063 INFO  VariantRecalibrator - Done initializing engine
15:54:45.063 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:54:45.063 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:45.064 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:54:45.064 INFO  ProgressMeter - Starting traversal
15:54:45.064 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:46.016 INFO  ProgressMeter -           20:9944766              0.0                131821        8316782.3
15:54:46.016 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:54:46.019 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:54:46.023 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:54:46.026 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:54:46.052 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:54:46.054 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:54:46.054 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:46.310 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:46.423 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:54:46.536 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:54:46.652 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:54:46.762 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:54:46.856 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:54:46.949 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:54:47.044 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:54:47.138 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:54:47.233 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:54:47.328 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:54:47.404 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:54:47.411 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:47.486 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:54:47.486 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:47.487 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:47.488 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:54:47.490 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:47.675 INFO  TrancheManager - Finding 12 tranches for 131821 variants
15:54:47.708 INFO  TrancheManager -   VQSLODTranche threshold 10.00 => selection metric threshold 0.900
15:54:47.718 INFO  TrancheManager -   Found tranche for 10.000: 0.900 threshold starting with variant 97819; running score is 0.262 
15:54:47.718 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=10.0000 known=(29048 @ 2.5026) novel=(4954 @ 2.3633) truthSites(18665 accessible, 13780 called), name=anonymous]
15:54:47.718 INFO  TrancheManager -   VQSLODTranche threshold 8.00 => selection metric threshold 0.920
15:54:47.723 INFO  TrancheManager -   Found tranche for 8.000: 0.920 threshold starting with variant 68875; running score is 0.114 
15:54:47.723 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=8.0000 known=(44004 @ 2.4829) novel=(18942 @ 2.4147) truthSites(18665 accessible, 16543 called), name=anonymous]
15:54:47.723 INFO  TrancheManager -   VQSLODTranche threshold 6.00 => selection metric threshold 0.940
15:54:47.728 INFO  TrancheManager -   Found tranche for 6.000: 0.940 threshold starting with variant 34094; running score is 0.052 
15:54:47.728 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=6.0000 known=(52474 @ 2.4242) novel=(45253 @ 2.3994) truthSites(18665 accessible, 17701 called), name=anonymous]
15:54:47.728 INFO  TrancheManager -   VQSLODTranche threshold 4.00 => selection metric threshold 0.960
15:54:47.733 INFO  TrancheManager -   Found tranche for 4.000: 0.960 threshold starting with variant 12275; running score is 0.023 
15:54:47.733 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=4.0000 known=(56181 @ 2.3913) novel=(63365 @ 2.3212) truthSites(18665 accessible, 18243 called), name=anonymous]
15:54:47.733 INFO  TrancheManager -   VQSLODTranche threshold 2.00 => selection metric threshold 0.980
15:54:47.738 INFO  TrancheManager -   Found tranche for 2.000: 0.980 threshold starting with variant 4952; running score is 0.009 
15:54:47.738 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=2.0000 known=(57758 @ 2.3573) novel=(69111 @ 2.2722) truthSites(18665 accessible, 18502 called), name=anonymous]
15:54:47.738 INFO  TrancheManager -   VQSLODTranche threshold 0.00 => selection metric threshold 1.000
15:54:47.742 INFO  TrancheManager -   Found tranche for 0.000: 1.000 threshold starting with variant 2260; running score is 0.004 
15:54:47.743 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=0.0000 known=(58579 @ 2.3306) novel=(70982 @ 2.2511) truthSites(18665 accessible, 18598 called), name=anonymous]
15:54:47.743 INFO  TrancheManager -   VQSLODTranche threshold -2.00 => selection metric threshold 1.020
15:54:47.747 INFO  TrancheManager -   Found tranche for -2.000: 1.020 threshold starting with variant 1099; running score is 0.001 
15:54:47.747 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-2.0000 known=(59019 @ 2.3111) novel=(71703 @ 2.2372) truthSites(18665 accessible, 18640 called), name=anonymous]
15:54:47.747 INFO  TrancheManager -   VQSLODTranche threshold -4.00 => selection metric threshold 1.040
15:54:47.752 INFO  TrancheManager -   Found tranche for -4.000: 1.040 threshold starting with variant 606; running score is 0.001 
15:54:47.752 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-4.0000 known=(59205 @ 2.3054) novel=(72010 @ 2.2272) truthSites(18665 accessible, 18648 called), name=anonymous]
15:54:47.752 INFO  TrancheManager -   VQSLODTranche threshold -6.00 => selection metric threshold 1.060
15:54:47.759 INFO  TrancheManager -   Found tranche for -6.000: 1.060 threshold starting with variant 429; running score is 0.001 
15:54:47.759 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-6.0000 known=(59292 @ 2.3026) novel=(72100 @ 2.2261) truthSites(18665 accessible, 18653 called), name=anonymous]
15:54:47.759 INFO  TrancheManager -   VQSLODTranche threshold -8.00 => selection metric threshold 1.080
15:54:47.763 INFO  TrancheManager -   Found tranche for -8.000: 1.080 threshold starting with variant 314; running score is 0.000 
15:54:47.764 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-8.0000 known=(59355 @ 2.3009) novel=(72152 @ 2.2247) truthSites(18665 accessible, 18657 called), name=anonymous]
15:54:47.764 INFO  TrancheManager -   VQSLODTranche threshold -10.00 => selection metric threshold 1.100
15:54:47.773 INFO  TrancheManager -   Found tranche for -10.000: 1.100 threshold starting with variant 264; running score is 0.000 
15:54:47.773 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-10.0000 known=(59372 @ 2.3008) novel=(72185 @ 2.2246) truthSites(18665 accessible, 18658 called), name=anonymous]
15:54:47.773 INFO  TrancheManager -   VQSLODTranche threshold -12.00 => selection metric threshold 1.120
15:54:47.781 INFO  TrancheManager -   Found tranche for -12.000: 1.120 threshold starting with variant 211; running score is 0.000 
15:54:47.781 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-12.0000 known=(59394 @ 2.3004) novel=(72216 @ 2.2244) truthSites(18665 accessible, 18659 called), name=anonymous]
15:54:47.781 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:48.100 INFO  VariantRecalibrator - Tranches plot will not be generated since we are running in scattered mode
15:54:48.106 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:48 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1168113664
15:54:48.130 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 3:54:49 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1168113664
15:54:49.580 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:49.580 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:49.581 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:49.581 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:49.581 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:49.581 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:49 PM UTC
15:54:49.581 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:49.581 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:49.581 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:49.581 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:49.581 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:49.581 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:49.581 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:49.581 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:49.581 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:49.581 INFO  VariantRecalibrator - Requester pays: disabled
15:54:49.581 INFO  VariantRecalibrator - Initializing engine
15:54:49.583 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
15:54:49.602 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
15:54:49.649 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:54:49.676 INFO  VariantRecalibrator - Done initializing engine
15:54:49.676 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:49.699 INFO  ProgressMeter - Starting traversal
15:54:49.699 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:49.784 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1970117.6
15:54:49.784 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:54:49.785 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:54:49.785 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:54:49.785 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:54:49.785 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:54:49.786 INFO  VariantDataManager - AS_FS: 	 mean = 1.08	 standard deviation = 2.43
15:54:49.786 INFO  VariantDataManager - AS_MQRankSum: 	 mean = 0.00	 standard deviation = 0.01
15:54:49.787 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR, AS_FS, AS_MQRankSum]
15:54:49.787 INFO  VariantDataManager - Training with 2769 variants after standard deviation thresholding.
15:54:49.787 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:49.842 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:49.886 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.56007
15:54:49.916 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.67355
15:54:49.942 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 5.08559
15:54:49.969 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.01567
15:54:49.995 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.02021
15:54:50.021 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01989
15:54:50.047 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02504
15:54:50.074 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03657
15:54:50.100 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.04057
15:54:50.126 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.08648
15:54:50.153 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.01514
15:54:50.179 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00496
15:54:50.205 INFO  VariantRecalibratorEngine - Finished iteration 65. 	Current change in mixture coefficients = 0.00163
15:54:50.205 INFO  VariantRecalibratorEngine - Convergence after 65 iterations!
15:54:50.208 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:54:50.227 INFO  VariantDataManager - Selected worst 5 scoring variants --> variants with LOD <= -5.0000.
15:54:50.227 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:50.227 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:50.227 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:54:50.227 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:54:50.241 INFO  TrancheManager - Finding 4 tranches for 2786 variants
15:54:50.241 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:54:50.241 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:54:50.242 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]
15:54:50.242 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:54:50.242 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
15:54:50.242 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]
15:54:50.242 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:54:50.242 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
15:54:50.242 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]
15:54:50.242 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:54:50.242 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
15:54:50.242 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]
15:54:50.243 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:50.258 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:50 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1168113664
15:54:50.259 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 3:54:52 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1168113664
[May 27, 2025 at 3:54:52 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1168113664
[May 27, 2025 at 3:54:52 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1168113664
[May 27, 2025 at 3:54:52 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1168113664
[May 27, 2025 at 3:54:53 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1168113664
[May 27, 2025 at 3:54:55 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1168113664
15:54:55.506 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:55.506 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:55.506 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:55.507 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:55.507 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:55.507 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:55 PM UTC
15:54:55.507 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:55.507 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:55.507 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:55.507 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:55.507 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:55.507 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:55.507 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:55.507 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:55.507 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:55.507 INFO  VariantRecalibrator - Requester pays: disabled
15:54:55.507 INFO  VariantRecalibrator - Initializing engine
15:54:55.508 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
15:54:55.511 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
15:54:55.512 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
15:54:55.514 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
15:54:55.517 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:54:55.518 INFO  VariantRecalibrator - Done initializing engine
15:54:55.518 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:54:55.518 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:55.518 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:54:55.519 INFO  ProgressMeter - Starting traversal
15:54:55.519 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:56.474 INFO  ProgressMeter -           20:9944766              0.0                131821        8281947.6
15:54:56.474 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:54:56.476 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:54:56.480 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:54:56.483 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:54:56.505 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:54:56.506 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:54:56.506 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:56.753 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:56.863 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:54:56.985 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:54:57.078 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:54:57.171 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:54:57.265 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:54:57.358 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:54:57.453 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:54:57.548 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:54:57.643 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:54:57.738 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:54:57.814 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:54:57.821 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:57.895 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:54:57.895 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:57.896 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:57.897 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:54:57.898 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:54:58.093 INFO  TrancheManager - Finding 12 tranches for 131821 variants
15:54:58.129 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:54:58.138 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:54:58.138 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]
15:54:58.138 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
15:54:58.144 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 381; running score is 0.001 
15:54:58.144 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]
15:54:58.144 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:54:58.149 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
15:54:58.149 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]
15:54:58.149 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
15:54:58.154 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 1480; running score is 0.002 
15:54:58.154 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]
15:54:58.154 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
15:54:58.159 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 2377; running score is 0.004 
15:54:58.160 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]
15:54:58.160 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
15:54:58.165 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 3042; running score is 0.005 
15:54:58.165 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]
15:54:58.165 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
15:54:58.170 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 3577; running score is 0.006 
15:54:58.170 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]
15:54:58.170 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
15:54:58.174 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 4004; running score is 0.007 
15:54:58.174 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]
15:54:58.174 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:54:58.179 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
15:54:58.179 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]
15:54:58.179 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
15:54:58.184 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 10673; running score is 0.020 
15:54:58.184 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]
15:54:58.184 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
15:54:58.191 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 16985; running score is 0.030 
15:54:58.191 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]
15:54:58.191 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:54:58.199 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
15:54:58.199 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]
15:54:58.199 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:58.521 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:58 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1168113664
15:54:58.545 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:54:58.552 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:58.552 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:54:58.552 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:54:58.552 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:54:58.552 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:54:58.552 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:54:58 PM UTC
15:54:58.552 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:58.552 INFO  VariantRecalibrator - ------------------------------------------------------------
15:54:58.552 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:54:58.553 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:54:58.553 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:54:58.553 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:54:58.553 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:54:58.553 INFO  VariantRecalibrator - Inflater: IntelInflater
15:54:58.553 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:54:58.553 INFO  VariantRecalibrator - Requester pays: disabled
15:54:58.553 INFO  VariantRecalibrator - Initializing engine
15:54:58.554 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
15:54:58.565 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
15:54:58.599 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:54:58.610 INFO  VariantRecalibrator - Done initializing engine
15:54:58.611 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:54:58.620 INFO  ProgressMeter - Starting traversal
15:54:58.621 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:54:58.664 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3987142.9
15:54:58.664 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:54:58.664 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:54:58.664 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:54:58.664 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:54:58.664 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:54:58.665 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
15:54:58.665 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
15:54:58.665 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:58.696 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:58.714 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
15:54:58.731 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
15:54:58.749 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
15:54:58.767 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
15:54:58.784 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
15:54:58.802 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
15:54:58.820 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
15:54:58.838 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
15:54:58.855 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
15:54:58.873 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
15:54:58.891 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
15:54:58.909 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
15:54:58.909 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
15:54:58.910 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:54:58.920 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
15:54:58.920 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:54:58.920 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:54:58.920 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:54:58.920 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:54:58.928 INFO  TrancheManager - Finding 12 tranches for 2786 variants
15:54:58.929 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:54:58.929 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:54:58.929 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]
15:54:58.929 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
15:54:58.929 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 2; running score is 0.001 
15:54:58.929 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]
15:54:58.929 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:54:58.929 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
15:54:58.929 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]
15:54:58.929 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
15:54:58.930 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 6; running score is 0.002 
15:54:58.930 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]
15:54:58.930 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
15:54:58.930 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 12; running score is 0.004 
15:54:58.930 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]
15:54:58.930 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
15:54:58.930 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 14; running score is 0.005 
15:54:58.930 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]
15:54:58.930 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
15:54:58.930 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 17; running score is 0.006 
15:54:58.930 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]
15:54:58.930 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
15:54:58.930 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 20; running score is 0.007 
15:54:58.930 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]
15:54:58.930 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:54:58.931 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
15:54:58.931 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]
15:54:58.931 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
15:54:58.931 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 56; running score is 0.020 
15:54:58.931 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]
15:54:58.931 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
15:54:58.931 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 84; running score is 0.030 
15:54:58.931 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]
15:54:58.931 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:54:58.931 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
15:54:58.931 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]
15:54:58.931 INFO  VariantRecalibrator - Writing out recalibration table...
15:54:58.945 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:54:58 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1168113664
[May 27, 2025 at 3:56:10 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1606418432