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

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

tests
0

failures
0

ignored
33.673s

duration
100%

successful

Tests

Test Duration Result
testAnnotationsWithNoVarianceSpecified 0.680s passed
testBothAggregateRecalMode 5.097s passed
testBothRecalMode 2.409s passed
testInGatkLiteDocker 0.087s passed
testNoNegativeTrainingData 0.611s passed
testVQSRAnnotationOrder 0.199s passed
testVariantRecalibratorIndel 0.863s passed
testVariantRecalibratorModelInput 1.308s passed
testVariantRecalibratorRScriptOutput 1.563s 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.075s 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.394s passed
testVariantRecalibratorSNPMaxAttempts[0]([Ljava.lang.String;@604d23fa) 5.698s 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.578s 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.107s 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.444s passed
testVariantRecalibratorSNPscattered[0]([Ljava.lang.String;@590765c4) 3.051s passed
testVariantRecalibratorSampling 1.509s passed

Standard output

--------------------------------------------------------------------------------
[16:44:23] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[16:44:45] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorSampling/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[16:44:47] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[16:44:49] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[16:44:49] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[16:44:49] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[16:44:50] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorIndel/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/combined.phase1.chr20.raw.indels.filtered.sites.1M-10M.vcf
--------------------------------------------------------------------------------
[16:44:50] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[16:46:04] 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 4:44:28 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.08 minutes.
Runtime.totalMemory()=641728512
16:44:28.644 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:28.644 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:28.644 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:28.644 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:28.644 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:28.645 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:28 PM UTC
16:44:28.645 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:28.645 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:28.645 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:28.645 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:28.645 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:28.645 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:28.645 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:28.645 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:28.646 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:28.646 INFO  VariantRecalibrator - Requester pays: disabled
16:44:28.646 INFO  VariantRecalibrator - Initializing engine
16:44:28.648 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
16:44:28.676 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
16:44:28.767 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
16:44:28.801 INFO  VariantRecalibrator - Done initializing engine
16:44:28.801 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:28.836 INFO  ProgressMeter - Starting traversal
16:44:28.836 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:28.953 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1431282.1
16:44:28.953 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
16:44:28.954 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
16:44:28.955 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
16:44:28.955 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
16:44:28.956 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
16:44:28.957 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
16:44:28.957 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
16:44:28.958 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:28.993 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:29.023 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.16919
16:44:29.039 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.14268
16:44:29.056 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.19617
16:44:29.079 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.09047
16:44:29.094 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.05235
16:44:29.110 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04028
16:44:29.126 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02103
16:44:29.141 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01461
16:44:29.157 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01136
16:44:29.174 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00583
16:44:29.196 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00291
16:44:29.205 INFO  VariantRecalibratorEngine - Convergence after 58 iterations!
16:44:29.208 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
16:44:29.224 INFO  VariantDataManager - Selected worst 0 scoring variants --> variants with LOD <= -5.5000.
16:44:29.233 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:29 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=641728512
16:44:29.238 INFO  gatk - Initializing VQSR tests/resetting random number generator
16:44:29.255 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:29.255 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:29.255 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:29.255 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:29.255 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:29.255 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:29 PM UTC
16:44:29.255 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:29.255 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:29.256 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:29.256 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:29.256 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:29.256 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:29.256 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:29.256 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:29.256 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:29.256 INFO  VariantRecalibrator - Requester pays: disabled
16:44:29.256 INFO  VariantRecalibrator - Initializing engine
16:44:29.258 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
16:44:29.262 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
16:44:29.264 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
16:44:29.267 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
16:44:29.272 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
16:44:29.274 INFO  VariantRecalibrator - Done initializing engine
16:44:29.275 WARN  VariantDataManager - Ignoring duplicate annotations for recalibration [HRun]
16:44:29.276 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
16:44:29.276 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:29.276 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
16:44:29.279 INFO  ProgressMeter - Starting traversal
16:44:29.279 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:30.518 INFO  ProgressMeter -           20:9944766              0.0                131821        6383583.5
16:44:30.519 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
16:44:30.523 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
16:44:30.534 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
16:44:30.538 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
16:44:30.639 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
16:44:30.642 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
16:44:30.642 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:30.885 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:30.990 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
16:44:31.106 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
16:44:31.213 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
16:44:31.333 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
16:44:31.430 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
16:44:31.527 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
16:44:31.632 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
16:44:31.728 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
16:44:31.821 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
16:44:31.913 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
16:44:31.987 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
16:44:31.998 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:32.069 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
16:44:32.070 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:32.071 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:32.072 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
16:44:32.073 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:32.255 INFO  TrancheManager - Finding 4 tranches for 131821 variants
16:44:32.288 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
16:44:32.293 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
16:44:32.293 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]
16:44:32.293 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
16:44:32.299 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
16:44:32.299 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]
16:44:32.299 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
16:44:32.304 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
16:44:32.304 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]
16:44:32.305 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
16:44:32.309 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
16:44:32.309 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]
16:44:32.310 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:32.757 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:32 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.06 minutes.
Runtime.totalMemory()=1124073472
16:44:32.817 INFO  gatk - Initializing VQSR tests/resetting random number generator
16:44:32.834 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:32.834 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:32.835 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:32.835 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:32.835 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:32.835 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:32 PM UTC
16:44:32.835 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:32.835 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:32.835 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:32.835 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:32.835 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:32.835 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:32.835 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:32.835 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:32.836 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:32.836 INFO  VariantRecalibrator - Requester pays: disabled
16:44:32.836 INFO  VariantRecalibrator - Initializing engine
16:44:32.837 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
16:44:32.841 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
16:44:32.844 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
16:44:32.850 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
16:44:32.855 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
16:44:32.857 INFO  VariantRecalibrator - Done initializing engine
16:44:32.857 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
16:44:32.857 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:32.857 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
16:44:32.859 INFO  ProgressMeter - Starting traversal
16:44:32.859 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:33.849 INFO  ProgressMeter -           20:9944766              0.0                131821        7989151.5
16:44:33.849 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
16:44:33.852 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
16:44:33.857 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
16:44:33.860 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
16:44:33.884 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
16:44:33.886 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
16:44:33.886 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:34.125 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:34.231 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
16:44:34.337 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
16:44:34.444 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
16:44:34.557 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
16:44:34.686 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
16:44:34.775 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
16:44:34.868 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
16:44:34.961 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
16:44:35.054 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
16:44:35.146 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
16:44:35.220 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
16:44:35.227 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:35.298 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
16:44:35.298 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:35.300 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:35.300 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
16:44:35.302 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:35.485 INFO  TrancheManager - Finding 4 tranches for 131821 variants
16:44:35.522 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
16:44:35.529 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
16:44:35.529 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]
16:44:35.529 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
16:44:35.535 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
16:44:35.535 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]
16:44:35.535 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
16:44:35.544 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
16:44:35.544 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]
16:44:35.544 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
16:44:35.560 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
16:44:35.561 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]
16:44:35.561 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:35.899 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:35 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1124073472
16:44:35.925 INFO  gatk - Initializing VQSR tests/resetting random number generator
16:44:35.937 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:35.938 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:35.938 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:35.938 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:35.938 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:35.938 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:35 PM UTC
16:44:35.938 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:35.938 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:35.938 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:35.938 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:35.939 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:35.939 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:35.939 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:35.939 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:35.939 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:35.939 INFO  VariantRecalibrator - Requester pays: disabled
16:44:35.939 INFO  VariantRecalibrator - Initializing engine
16:44:35.941 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
16:44:35.954 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
16:44:35.994 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
16:44:36.013 INFO  VariantRecalibrator - Done initializing engine
16:44:36.013 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:36.027 INFO  ProgressMeter - Starting traversal
16:44:36.028 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:36.072 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3805909.1
16:44:36.073 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
16:44:36.073 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
16:44:36.073 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
16:44:36.073 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
16:44:36.073 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
16:44:36.074 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
16:44:36.074 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
16:44:36.074 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:36.103 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:36.120 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
16:44:36.137 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
16:44:36.154 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
16:44:36.172 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
16:44:36.189 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
16:44:36.206 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
16:44:36.223 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
16:44:36.241 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
16:44:36.258 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
16:44:36.275 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
16:44:36.292 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
16:44:36.309 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
16:44:36.309 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
16:44:36.310 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
16:44:36.321 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
16:44:36.321 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:36.321 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:36.321 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
16:44:36.321 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
16:44:36.334 INFO  TrancheManager - Finding 4 tranches for 2786 variants
16:44:36.336 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
16:44:36.336 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
16:44:36.336 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]
16:44:36.336 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
16:44:36.337 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
16:44:36.337 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]
16:44:36.337 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
16:44:36.337 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
16:44:36.337 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]
16:44:36.337 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
16:44:36.338 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
16:44:36.338 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]
16:44:36.338 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:36.366 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:36 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1124073472
16:44:36.372 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 4:44:38 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1124073472
16:44:38.940 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:38.940 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:38.940 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:38.940 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:38.940 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:38.940 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:38 PM UTC
16:44:38.940 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:38.941 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:38.941 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:38.941 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:38.941 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:38.941 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:38.941 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:38.941 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:38.941 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:38.941 INFO  VariantRecalibrator - Requester pays: disabled
16:44:38.941 INFO  VariantRecalibrator - Initializing engine
16:44:38.942 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
16:44:38.945 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
16:44:38.948 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
16:44:38.950 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
16:44:38.953 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
16:44:38.975 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
16:44:38.977 INFO  VariantRecalibrator - Done initializing engine
16:44:38.977 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
16:44:38.977 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:38.977 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
16:44:38.981 INFO  ProgressMeter - Starting traversal
16:44:38.981 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:40.064 INFO  ProgressMeter -           20:9938789              0.0                134919        7474736.8
16:44:40.064 INFO  ProgressMeter - Traversal complete. Processed 134919 total variants in 0.0 minutes.
16:44:40.066 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
16:44:40.072 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
16:44:40.077 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
16:44:40.114 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
16:44:40.116 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
16:44:40.116 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:40.304 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:40.384 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.13181
16:44:40.483 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.46782
16:44:40.571 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 9.04961
16:44:40.665 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.04477
16:44:40.752 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01711
16:44:40.837 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.02053
16:44:40.925 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.01194
16:44:41.026 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01038
16:44:41.113 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.06192
16:44:41.201 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01281
16:44:41.301 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00457
16:44:41.331 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
16:44:41.336 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
16:44:41.454 INFO  VariantDataManager - Selected worst 754 scoring variants --> variants with LOD <= -5.0000.
16:44:41.454 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:41.456 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:41.458 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.05287
16:44:41.459 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.02030
16:44:41.460 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.00986
16:44:41.461 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.00749
16:44:41.463 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.00850
16:44:41.464 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01430
16:44:41.465 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02541
16:44:41.466 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.02173
16:44:41.468 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01024
16:44:41.469 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00479
16:44:41.470 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00245
16:44:41.471 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
16:44:41.473 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
16:44:41.671 INFO  TrancheManager - Finding 4 tranches for 134603 variants
16:44:41.723 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
16:44:41.734 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
16:44:41.734 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]
16:44:41.734 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
16:44:41.741 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 649; running score is 0.001 
16:44:41.741 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]
16:44:41.741 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
16:44:41.746 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 7924; running score is 0.010 
16:44:41.746 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]
16:44:41.746 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
16:44:41.751 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 52632; running score is 0.100 
16:44:41.751 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]
16:44:41.751 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:42.069 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:42 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1124073472
16:44:42.071 INFO  gatk - Initializing VQSR tests/resetting random number generator
16:44:42.079 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:42.079 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:42.079 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:42.079 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:42.079 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:42.079 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:42 PM UTC
16:44:42.079 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:42.080 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:42.080 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:42.080 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:42.080 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:42.080 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:42.080 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:42.080 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:42.080 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:42.080 INFO  VariantRecalibrator - Requester pays: disabled
16:44:42.080 INFO  VariantRecalibrator - Initializing engine
16:44:42.081 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
16:44:42.083 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
16:44:42.084 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
16:44:42.086 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
16:44:42.088 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
16:44:42.089 INFO  VariantRecalibrator - Done initializing engine
16:44:42.089 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
16:44:42.089 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:42.089 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
16:44:42.090 INFO  ProgressMeter - Starting traversal
16:44:42.090 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:43.031 INFO  ProgressMeter -           20:9944766              0.0                131821        8405164.7
16:44:43.031 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
16:44:43.034 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
16:44:43.038 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
16:44:43.042 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
16:44:43.066 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
16:44:43.068 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
16:44:43.068 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:43.309 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:43.415 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
16:44:43.535 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
16:44:43.639 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
16:44:43.730 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
16:44:43.820 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
16:44:43.910 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
16:44:44.001 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
16:44:44.093 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
16:44:44.185 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
16:44:44.277 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
16:44:44.351 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
16:44:44.358 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:44.431 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
16:44:44.431 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:44.432 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:44.433 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
16:44:44.434 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:44.628 INFO  TrancheManager - Finding 12 tranches for 131821 variants
16:44:44.675 INFO  TrancheManager -   VQSLODTranche threshold 10.00 => selection metric threshold 0.900
16:44:44.690 INFO  TrancheManager -   Found tranche for 10.000: 0.900 threshold starting with variant 97819; running score is 0.262 
16:44:44.690 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=10.0000 known=(29048 @ 2.5026) novel=(4954 @ 2.3633) truthSites(18665 accessible, 13780 called), name=anonymous]
16:44:44.690 INFO  TrancheManager -   VQSLODTranche threshold 8.00 => selection metric threshold 0.920
16:44:44.697 INFO  TrancheManager -   Found tranche for 8.000: 0.920 threshold starting with variant 68875; running score is 0.114 
16:44:44.697 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=8.0000 known=(44004 @ 2.4829) novel=(18942 @ 2.4147) truthSites(18665 accessible, 16543 called), name=anonymous]
16:44:44.697 INFO  TrancheManager -   VQSLODTranche threshold 6.00 => selection metric threshold 0.940
16:44:44.703 INFO  TrancheManager -   Found tranche for 6.000: 0.940 threshold starting with variant 34094; running score is 0.052 
16:44:44.703 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=6.0000 known=(52474 @ 2.4242) novel=(45253 @ 2.3994) truthSites(18665 accessible, 17701 called), name=anonymous]
16:44:44.703 INFO  TrancheManager -   VQSLODTranche threshold 4.00 => selection metric threshold 0.960
16:44:44.708 INFO  TrancheManager -   Found tranche for 4.000: 0.960 threshold starting with variant 12275; running score is 0.023 
16:44:44.708 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=4.0000 known=(56181 @ 2.3913) novel=(63365 @ 2.3212) truthSites(18665 accessible, 18243 called), name=anonymous]
16:44:44.708 INFO  TrancheManager -   VQSLODTranche threshold 2.00 => selection metric threshold 0.980
16:44:44.718 INFO  TrancheManager -   Found tranche for 2.000: 0.980 threshold starting with variant 4952; running score is 0.009 
16:44:44.718 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=2.0000 known=(57758 @ 2.3573) novel=(69111 @ 2.2722) truthSites(18665 accessible, 18502 called), name=anonymous]
16:44:44.718 INFO  TrancheManager -   VQSLODTranche threshold 0.00 => selection metric threshold 1.000
16:44:44.733 INFO  TrancheManager -   Found tranche for 0.000: 1.000 threshold starting with variant 2260; running score is 0.004 
16:44:44.733 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=0.0000 known=(58579 @ 2.3306) novel=(70982 @ 2.2511) truthSites(18665 accessible, 18598 called), name=anonymous]
16:44:44.733 INFO  TrancheManager -   VQSLODTranche threshold -2.00 => selection metric threshold 1.020
16:44:44.747 INFO  TrancheManager -   Found tranche for -2.000: 1.020 threshold starting with variant 1099; running score is 0.001 
16:44:44.747 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-2.0000 known=(59019 @ 2.3111) novel=(71703 @ 2.2372) truthSites(18665 accessible, 18640 called), name=anonymous]
16:44:44.747 INFO  TrancheManager -   VQSLODTranche threshold -4.00 => selection metric threshold 1.040
16:44:44.753 INFO  TrancheManager -   Found tranche for -4.000: 1.040 threshold starting with variant 606; running score is 0.001 
16:44:44.753 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-4.0000 known=(59205 @ 2.3054) novel=(72010 @ 2.2272) truthSites(18665 accessible, 18648 called), name=anonymous]
16:44:44.753 INFO  TrancheManager -   VQSLODTranche threshold -6.00 => selection metric threshold 1.060
16:44:44.758 INFO  TrancheManager -   Found tranche for -6.000: 1.060 threshold starting with variant 429; running score is 0.001 
16:44:44.758 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-6.0000 known=(59292 @ 2.3026) novel=(72100 @ 2.2261) truthSites(18665 accessible, 18653 called), name=anonymous]
16:44:44.758 INFO  TrancheManager -   VQSLODTranche threshold -8.00 => selection metric threshold 1.080
16:44:44.762 INFO  TrancheManager -   Found tranche for -8.000: 1.080 threshold starting with variant 314; running score is 0.000 
16:44:44.762 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-8.0000 known=(59355 @ 2.3009) novel=(72152 @ 2.2247) truthSites(18665 accessible, 18657 called), name=anonymous]
16:44:44.762 INFO  TrancheManager -   VQSLODTranche threshold -10.00 => selection metric threshold 1.100
16:44:44.768 INFO  TrancheManager -   Found tranche for -10.000: 1.100 threshold starting with variant 264; running score is 0.000 
16:44:44.768 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-10.0000 known=(59372 @ 2.3008) novel=(72185 @ 2.2246) truthSites(18665 accessible, 18658 called), name=anonymous]
16:44:44.768 INFO  TrancheManager -   VQSLODTranche threshold -12.00 => selection metric threshold 1.120
16:44:44.775 INFO  TrancheManager -   Found tranche for -12.000: 1.120 threshold starting with variant 211; running score is 0.000 
16:44:44.775 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-12.0000 known=(59394 @ 2.3004) novel=(72216 @ 2.2244) truthSites(18665 accessible, 18659 called), name=anonymous]
16:44:44.775 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:45.088 INFO  VariantRecalibrator - Tranches plot will not be generated since we are running in scattered mode
16:44:45.094 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:45 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1124073472
16:44:45.123 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 4:44:46 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1124073472
16:44:46.645 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:46.645 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:46.646 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:46.646 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:46.646 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:46.646 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:46 PM UTC
16:44:46.646 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:46.646 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:46.646 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:46.646 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:46.646 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:46.646 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:46.646 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:46.646 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:46.646 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:46.646 INFO  VariantRecalibrator - Requester pays: disabled
16:44:46.646 INFO  VariantRecalibrator - Initializing engine
16:44:46.647 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
16:44:46.665 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
16:44:46.723 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
16:44:46.749 INFO  VariantRecalibrator - Done initializing engine
16:44:46.749 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:46.771 INFO  ProgressMeter - Starting traversal
16:44:46.772 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:46.853 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        2067407.4
16:44:46.853 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
16:44:46.854 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
16:44:46.854 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
16:44:46.854 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
16:44:46.854 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
16:44:46.854 INFO  VariantDataManager - AS_FS: 	 mean = 1.08	 standard deviation = 2.43
16:44:46.855 INFO  VariantDataManager - AS_MQRankSum: 	 mean = 0.00	 standard deviation = 0.01
16:44:46.856 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR, AS_FS, AS_MQRankSum]
16:44:46.856 INFO  VariantDataManager - Training with 2769 variants after standard deviation thresholding.
16:44:46.856 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:46.909 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:46.951 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.56007
16:44:46.981 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.67355
16:44:47.006 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 5.08559
16:44:47.031 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.01567
16:44:47.057 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.02021
16:44:47.082 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01989
16:44:47.107 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02504
16:44:47.132 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03657
16:44:47.157 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.04057
16:44:47.183 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.08648
16:44:47.208 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.01514
16:44:47.233 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00496
16:44:47.259 INFO  VariantRecalibratorEngine - Finished iteration 65. 	Current change in mixture coefficients = 0.00163
16:44:47.259 INFO  VariantRecalibratorEngine - Convergence after 65 iterations!
16:44:47.261 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
16:44:47.279 INFO  VariantDataManager - Selected worst 5 scoring variants --> variants with LOD <= -5.0000.
16:44:47.279 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:47.280 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:47.280 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
16:44:47.280 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
16:44:47.293 INFO  TrancheManager - Finding 4 tranches for 2786 variants
16:44:47.293 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
16:44:47.294 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
16:44:47.294 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]
16:44:47.294 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
16:44:47.294 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
16:44:47.294 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]
16:44:47.294 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
16:44:47.294 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
16:44:47.294 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]
16:44:47.294 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
16:44:47.295 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
16:44:47.295 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]
16:44:47.295 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:47.313 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:47 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1124073472
16:44:47.315 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 4:44:49 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1124073472
[May 27, 2025 at 4:44:49 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1124073472
[May 27, 2025 at 4:44:49 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1124073472
[May 27, 2025 at 4:44:50 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1124073472
[May 27, 2025 at 4:44:50 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1124073472
[May 27, 2025 at 4:44:52 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1124073472
16:44:52.452 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:52.453 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:52.453 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:52.453 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:52.453 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:52.453 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:52 PM UTC
16:44:52.453 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:52.453 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:52.453 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:52.453 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:52.453 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:52.454 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:52.454 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:52.454 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:52.454 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:52.454 INFO  VariantRecalibrator - Requester pays: disabled
16:44:52.454 INFO  VariantRecalibrator - Initializing engine
16:44:52.455 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
16:44:52.457 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
16:44:52.459 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
16:44:52.461 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
16:44:52.464 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
16:44:52.465 INFO  VariantRecalibrator - Done initializing engine
16:44:52.465 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
16:44:52.465 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:52.465 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
16:44:52.466 INFO  ProgressMeter - Starting traversal
16:44:52.466 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:53.444 INFO  ProgressMeter -           20:9944766              0.0                131821        8087177.9
16:44:53.444 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
16:44:53.446 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
16:44:53.450 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
16:44:53.454 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
16:44:53.478 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
16:44:53.480 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
16:44:53.480 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:53.722 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:53.829 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
16:44:53.935 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
16:44:54.049 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
16:44:54.138 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
16:44:54.228 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
16:44:54.318 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
16:44:54.410 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
16:44:54.502 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
16:44:54.594 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
16:44:54.687 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
16:44:54.760 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
16:44:54.767 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:54.836 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
16:44:54.836 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:54.837 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:54.838 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
16:44:54.840 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
16:44:55.028 INFO  TrancheManager - Finding 12 tranches for 131821 variants
16:44:55.063 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
16:44:55.069 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
16:44:55.069 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]
16:44:55.069 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
16:44:55.074 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 381; running score is 0.001 
16:44:55.074 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]
16:44:55.074 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
16:44:55.080 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
16:44:55.080 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]
16:44:55.080 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
16:44:55.087 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 1480; running score is 0.002 
16:44:55.087 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]
16:44:55.087 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
16:44:55.095 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 2377; running score is 0.004 
16:44:55.095 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]
16:44:55.095 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
16:44:55.108 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 3042; running score is 0.005 
16:44:55.108 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]
16:44:55.108 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
16:44:55.119 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 3577; running score is 0.006 
16:44:55.119 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]
16:44:55.119 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
16:44:55.130 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 4004; running score is 0.007 
16:44:55.130 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]
16:44:55.130 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
16:44:55.140 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
16:44:55.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]
16:44:55.141 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
16:44:55.149 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 10673; running score is 0.020 
16:44:55.149 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]
16:44:55.149 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
16:44:55.163 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 16985; running score is 0.030 
16:44:55.163 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]
16:44:55.163 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
16:44:55.177 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
16:44:55.177 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]
16:44:55.177 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:55.494 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:55 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1124073472
16:44:55.517 INFO  gatk - Initializing VQSR tests/resetting random number generator
16:44:55.524 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:55.524 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
16:44:55.524 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
16:44:55.524 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
16:44:55.525 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
16:44:55.525 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 4:44:55 PM UTC
16:44:55.525 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:55.525 INFO  VariantRecalibrator - ------------------------------------------------------------
16:44:55.525 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
16:44:55.525 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
16:44:55.525 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
16:44:55.525 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
16:44:55.525 INFO  VariantRecalibrator - Deflater: IntelDeflater
16:44:55.525 INFO  VariantRecalibrator - Inflater: IntelInflater
16:44:55.525 INFO  VariantRecalibrator - GCS max retries/reopens: 20
16:44:55.525 INFO  VariantRecalibrator - Requester pays: disabled
16:44:55.525 INFO  VariantRecalibrator - Initializing engine
16:44:55.526 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
16:44:55.535 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
16:44:55.569 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
16:44:55.586 INFO  VariantRecalibrator - Done initializing engine
16:44:55.586 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
16:44:55.597 INFO  ProgressMeter - Starting traversal
16:44:55.597 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
16:44:55.641 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3805909.1
16:44:55.641 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
16:44:55.642 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
16:44:55.642 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
16:44:55.642 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
16:44:55.642 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
16:44:55.643 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
16:44:55.643 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
16:44:55.643 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:55.672 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:55.689 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
16:44:55.707 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
16:44:55.724 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
16:44:55.741 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
16:44:55.757 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
16:44:55.774 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
16:44:55.791 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
16:44:55.807 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
16:44:55.824 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
16:44:55.841 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
16:44:55.857 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
16:44:55.874 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
16:44:55.874 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
16:44:55.876 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
16:44:55.884 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
16:44:55.884 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
16:44:55.884 INFO  VariantRecalibratorEngine - Finished iteration 0.
16:44:55.884 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
16:44:55.885 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
16:44:55.892 INFO  TrancheManager - Finding 12 tranches for 2786 variants
16:44:55.893 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
16:44:55.893 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
16:44:55.893 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]
16:44:55.893 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
16:44:55.894 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 2; running score is 0.001 
16:44:55.894 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]
16:44:55.894 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
16:44:55.894 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
16:44:55.894 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]
16:44:55.894 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
16:44:55.894 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 6; running score is 0.002 
16:44:55.894 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]
16:44:55.894 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
16:44:55.894 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 12; running score is 0.004 
16:44:55.894 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]
16:44:55.894 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
16:44:55.895 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 14; running score is 0.005 
16:44:55.895 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]
16:44:55.895 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
16:44:55.895 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 17; running score is 0.006 
16:44:55.895 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]
16:44:55.895 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
16:44:55.895 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 20; running score is 0.007 
16:44:55.895 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]
16:44:55.895 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
16:44:55.895 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
16:44:55.895 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]
16:44:55.895 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
16:44:55.896 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 56; running score is 0.020 
16:44:55.896 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]
16:44:55.896 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
16:44:55.896 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 84; running score is 0.030 
16:44:55.896 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]
16:44:55.896 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
16:44:55.896 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
16:44:55.896 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]
16:44:55.896 INFO  VariantRecalibrator - Writing out recalibration table...
16:44:55.909 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 4:44:55 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1124073472
[May 27, 2025 at 4:46:05 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1140850688