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

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

tests
0

failures
0

ignored
32.441s

duration
100%

successful

Tests

Test Duration Result
testAnnotationsWithNoVarianceSpecified 0.584s passed
testBothAggregateRecalMode 4.807s passed
testBothRecalMode 2.406s passed
testInGatkLiteDocker 0.081s passed
testNoNegativeTrainingData 0.509s passed
testVQSRAnnotationOrder 0.201s passed
testVariantRecalibratorIndel 0.803s passed
testVariantRecalibratorModelInput 1.228s passed
testVariantRecalibratorRScriptOutput 1.577s passed
testVariantRecalibratorSNPAlternateTranches[0]([Ljava.lang.String;@67bd351e, /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.121s passed
testVariantRecalibratorSNPAlternateTranches[1]([Ljava.lang.String;@4b862408, /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.413s passed
testVariantRecalibratorSNPMaxAttempts[0]([Ljava.lang.String;@45117dd) 5.366s passed
testVariantRecalibratorSNP[0]([Ljava.lang.String;@47148f3f, /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.381s passed
testVariantRecalibratorSNP[1]([Ljava.lang.String;@67bd351e, /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.035s passed
testVariantRecalibratorSNP[2]([Ljava.lang.String;@4b862408, /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.547s passed
testVariantRecalibratorSNPscattered[0]([Ljava.lang.String;@7126e26) 3.013s passed
testVariantRecalibratorSampling 1.369s passed

Standard output

--------------------------------------------------------------------------------
[15:06:37] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[15:06:58] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorSampling/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[15:07:00] Executing test VariantRecalibratorIntegrationTest:testBothRecalMode
--------------------------------------------------------------------------------
[15:07:03] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[15:07:03] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[15:07:03] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorModelInput/home/runner/work/gatk/gatk/src/test/resources//oneSNP.vcf
--------------------------------------------------------------------------------
[15:07:03] 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:07:04] Executing test VariantRecalibratorIntegrationTest:testVariantRecalibratorRscriptOutput/home/runner/work/gatk/gatk/src/test/resources/large/VQSR/phase1.projectConsensus.chr20.1M-10M.raw.snps.vcf
--------------------------------------------------------------------------------
[15:08:14] 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:06:42 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.07 minutes.
Runtime.totalMemory()=715128832
15:06:42.810 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:42.810 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:06:42.810 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:06:42.811 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:06:42.811 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:06:42.811 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:06:42 PM UTC
15:06:42.811 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:42.811 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:42.811 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:06:42.812 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:06:42.812 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:06:42.812 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:06:42.812 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:06:42.812 INFO  VariantRecalibrator - Inflater: IntelInflater
15:06:42.812 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:06:42.812 INFO  VariantRecalibrator - Requester pays: disabled
15:06:42.812 INFO  VariantRecalibrator - Initializing engine
15:06:42.815 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:06:42.832 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:06:42.886 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:06:42.906 INFO  VariantRecalibrator - Done initializing engine
15:06:42.907 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:06:42.932 INFO  ProgressMeter - Starting traversal
15:06:42.932 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:06:43.025 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1800645.2
15:06:43.025 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:06:43.026 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:06:43.026 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:06:43.027 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:06:43.028 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:06:43.030 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
15:06:43.030 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
15:06:43.031 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:43.072 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:43.091 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.16919
15:06:43.108 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.14268
15:06:43.127 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.19617
15:06:43.144 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.09047
15:06:43.162 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.05235
15:06:43.181 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04028
15:06:43.199 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02103
15:06:43.216 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01461
15:06:43.234 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01136
15:06:43.252 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00583
15:06:43.269 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00291
15:06:43.280 INFO  VariantRecalibratorEngine - Convergence after 58 iterations!
15:06:43.282 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:06:43.292 INFO  VariantDataManager - Selected worst 0 scoring variants --> variants with LOD <= -5.5000.
15:06:43.298 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:06:43 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=715128832
15:06:43.302 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:06:43.320 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:43.320 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:06:43.320 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:06:43.320 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:06:43.320 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:06:43.320 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:06:43 PM UTC
15:06:43.320 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:43.320 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:43.321 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:06:43.321 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:06:43.321 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:06:43.321 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:06:43.321 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:06:43.321 INFO  VariantRecalibrator - Inflater: IntelInflater
15:06:43.321 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:06:43.321 INFO  VariantRecalibrator - Requester pays: disabled
15:06:43.321 INFO  VariantRecalibrator - Initializing engine
15:06:43.323 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:06:43.326 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:06:43.328 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:06:43.330 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:06:43.334 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:06:43.335 INFO  VariantRecalibrator - Done initializing engine
15:06:43.337 WARN  VariantDataManager - Ignoring duplicate annotations for recalibration [HRun]
15:06:43.337 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:06:43.337 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:06:43.337 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:06:43.340 INFO  ProgressMeter - Starting traversal
15:06:43.340 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:06:44.404 INFO  ProgressMeter -           20:9944766              0.0                131821        7440508.0
15:06:44.404 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:06:44.408 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:06:44.420 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:06:44.425 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:06:44.541 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:06:44.546 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:06:44.546 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:44.805 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:44.915 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:06:45.026 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:06:45.138 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:06:45.266 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:06:45.363 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:06:45.460 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:06:45.558 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:06:45.652 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:06:45.745 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:06:45.839 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:06:45.915 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:06:45.922 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:06:45.995 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:06:45.995 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:45.997 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:45.998 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:06:46.000 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:06:46.189 INFO  TrancheManager - Finding 4 tranches for 131821 variants
15:06:46.229 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:06:46.233 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:06:46.234 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:06:46.234 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:06:46.238 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
15:06:46.239 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:06:46.239 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:06:46.245 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
15:06:46.245 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:06:46.245 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:06:46.252 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
15:06:46.253 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:06:46.253 INFO  VariantRecalibrator - Writing out recalibration table...
15:06:46.655 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:06:46 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.06 minutes.
Runtime.totalMemory()=1107296256
15:06:46.685 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:06:46.701 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:46.701 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:06:46.701 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:06:46.701 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:06:46.701 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:06:46.701 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:06:46 PM UTC
15:06:46.701 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:46.701 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:46.701 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:06:46.701 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:06:46.702 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:06:46.702 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:06:46.702 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:06:46.702 INFO  VariantRecalibrator - Inflater: IntelInflater
15:06:46.702 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:06:46.702 INFO  VariantRecalibrator - Requester pays: disabled
15:06:46.702 INFO  VariantRecalibrator - Initializing engine
15:06:46.704 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:06:46.706 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:06:46.708 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:06:46.714 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:06:46.719 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:06:46.720 INFO  VariantRecalibrator - Done initializing engine
15:06:46.721 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:06:46.721 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:06:46.721 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:06:46.725 INFO  ProgressMeter - Starting traversal
15:06:46.726 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:06:47.671 INFO  ProgressMeter -           20:9944766              0.0                131821        8369587.3
15:06:47.671 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:06:47.674 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:06:47.678 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:06:47.681 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:06:47.703 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:06:47.705 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:06:47.705 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:47.958 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:48.067 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:06:48.177 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:06:48.289 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:06:48.402 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:06:48.526 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:06:48.616 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:06:48.709 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:06:48.802 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:06:48.895 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:06:48.988 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:06:49.062 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:06:49.069 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:06:49.142 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:06:49.142 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:49.143 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:49.144 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:06:49.146 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:06:49.328 INFO  TrancheManager - Finding 4 tranches for 131821 variants
15:06:49.360 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:06:49.365 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:06:49.365 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:06:49.365 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:06:49.369 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
15:06:49.369 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:06:49.370 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:06:49.374 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
15:06:49.374 INFO  TrancheManager -   TruthSensitivityTranche is TruthSensitivityTranche targetTruthSensitivity=99.00 minVQSLod=2.2535 known=(57628 @ 2.3617) novel=(68589 @ 2.2769) truthSites(18665 accessible, 18478 called), name=anonymous]
15:06:49.374 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:06:49.379 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
15:06:49.379 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:06:49.379 INFO  VariantRecalibrator - Writing out recalibration table...
15:06:49.696 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:06:49 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1107296256
15:06:49.721 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:06:49.733 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:49.733 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:06:49.733 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:06:49.733 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:06:49.733 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:06:49.733 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:06:49 PM UTC
15:06:49.733 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:49.733 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:49.734 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:06:49.734 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:06:49.734 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:06:49.734 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:06:49.734 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:06:49.734 INFO  VariantRecalibrator - Inflater: IntelInflater
15:06:49.735 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:06:49.735 INFO  VariantRecalibrator - Requester pays: disabled
15:06:49.735 INFO  VariantRecalibrator - Initializing engine
15:06:49.737 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:06:49.758 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:06:49.822 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:06:49.842 INFO  VariantRecalibrator - Done initializing engine
15:06:49.843 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:06:49.860 INFO  ProgressMeter - Starting traversal
15:06:49.860 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:06:49.953 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        1820217.4
15:06:49.953 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:06:49.953 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:06:49.953 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:06:49.953 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:06:49.954 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:06:49.955 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
15:06:49.955 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
15:06:49.955 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:49.997 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:50.015 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
15:06:50.033 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
15:06:50.051 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
15:06:50.069 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
15:06:50.087 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
15:06:50.104 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
15:06:50.122 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
15:06:50.141 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
15:06:50.158 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
15:06:50.176 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
15:06:50.193 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
15:06:50.211 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
15:06:50.211 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
15:06:50.213 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:06:50.223 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
15:06:50.223 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:50.223 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:50.223 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:06:50.223 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:06:50.234 INFO  TrancheManager - Finding 4 tranches for 2786 variants
15:06:50.236 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:06:50.236 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:06:50.236 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:06:50.237 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:06:50.237 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
15:06:50.237 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:06:50.237 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:06:50.237 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
15:06:50.237 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:06:50.238 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:06:50.238 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
15:06:50.238 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:06:50.238 INFO  VariantRecalibrator - Writing out recalibration table...
15:06:50.266 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:06:50 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1107296256
15:06:50.269 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 3:06:52 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1107296256
15:06:52.708 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:52.708 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:06:52.708 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:06:52.708 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:06:52.708 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:06:52.708 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:06:52 PM UTC
15:06:52.708 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:52.709 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:52.709 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:06:52.709 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:06:52.709 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:06:52.709 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:06:52.709 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:06:52.709 INFO  VariantRecalibrator - Inflater: IntelInflater
15:06:52.709 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:06:52.709 INFO  VariantRecalibrator - Requester pays: disabled
15:06:52.709 INFO  VariantRecalibrator - Initializing engine
15:06:52.711 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:06:52.714 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:06:52.716 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:06:52.718 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:06:52.720 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:06:52.738 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:06:52.739 INFO  VariantRecalibrator - Done initializing engine
15:06:52.740 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:06:52.740 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:06:52.740 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:06:52.743 INFO  ProgressMeter - Starting traversal
15:06:52.743 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:06:53.728 INFO  ProgressMeter -           20:9938789              0.0                134919        8218416.2
15:06:53.729 INFO  ProgressMeter - Traversal complete. Processed 134919 total variants in 0.0 minutes.
15:06:53.731 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:06:53.735 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:06:53.737 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:06:53.757 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:06:53.758 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:06:53.758 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:53.952 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:54.035 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.13181
15:06:54.119 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.46782
15:06:54.205 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 9.04961
15:06:54.293 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.04477
15:06:54.381 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01711
15:06:54.469 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.02053
15:06:54.557 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.01194
15:06:54.645 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.01038
15:06:54.733 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.06192
15:06:54.829 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01281
15:06:54.902 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00457
15:06:54.932 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
15:06:54.937 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
15:06:55.054 INFO  VariantDataManager - Selected worst 754 scoring variants --> variants with LOD <= -5.0000.
15:06:55.054 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:55.056 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:55.058 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.05287
15:06:55.059 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.02030
15:06:55.060 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.00986
15:06:55.062 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.00749
15:06:55.063 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.00850
15:06:55.064 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01430
15:06:55.066 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02541
15:06:55.067 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.02173
15:06:55.068 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.01024
15:06:55.069 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00479
15:06:55.071 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00245
15:06:55.071 INFO  VariantRecalibratorEngine - Convergence after 57 iterations!
15:06:55.073 INFO  VariantRecalibratorEngine - Evaluating full set of 134603 variants...
15:06:55.268 INFO  TrancheManager - Finding 4 tranches for 134603 variants
15:06:55.308 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:06:55.313 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:06:55.313 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:06:55.313 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:06:55.318 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 649; running score is 0.001 
15:06:55.318 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:06:55.318 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:06:55.323 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 7924; running score is 0.010 
15:06:55.323 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:06:55.323 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:06:55.327 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 52632; running score is 0.100 
15:06:55.327 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:06:55.327 INFO  VariantRecalibrator - Writing out recalibration table...
15:06:55.635 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:06:55 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1107296256
15:06:55.638 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:06:55.650 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:55.650 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:06:55.650 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:06:55.650 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:06:55.650 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:06:55.651 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:06:55 PM UTC
15:06:55.651 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:55.651 INFO  VariantRecalibrator - ------------------------------------------------------------
15:06:55.651 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:06:55.651 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:06:55.651 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:06:55.651 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:06:55.651 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:06:55.651 INFO  VariantRecalibrator - Inflater: IntelInflater
15:06:55.651 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:06:55.651 INFO  VariantRecalibrator - Requester pays: disabled
15:06:55.651 INFO  VariantRecalibrator - Initializing engine
15:06:55.653 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:06:55.655 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:06:55.657 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:06:55.659 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:06:55.662 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:06:55.663 INFO  VariantRecalibrator - Done initializing engine
15:06:55.663 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:06:55.664 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:06:55.664 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:06:55.665 INFO  ProgressMeter - Starting traversal
15:06:55.665 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:06:56.649 INFO  ProgressMeter -           20:9944766              0.0                131821        8037865.9
15:06:56.649 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:06:56.652 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:06:56.657 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:06:56.660 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:06:56.682 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:06:56.684 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:06:56.684 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:56.934 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:57.048 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:06:57.135 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:06:57.224 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:06:57.315 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:06:57.407 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:06:57.496 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:06:57.589 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:06:57.682 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:06:57.775 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:06:57.868 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:06:57.951 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:06:57.958 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:06:58.035 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:06:58.035 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:06:58.037 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:06:58.037 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:06:58.039 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:06:58.222 INFO  TrancheManager - Finding 12 tranches for 131821 variants
15:06:58.258 INFO  TrancheManager -   VQSLODTranche threshold 10.00 => selection metric threshold 0.900
15:06:58.267 INFO  TrancheManager -   Found tranche for 10.000: 0.900 threshold starting with variant 97819; running score is 0.262 
15:06:58.267 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=10.0000 known=(29048 @ 2.5026) novel=(4954 @ 2.3633) truthSites(18665 accessible, 13780 called), name=anonymous]
15:06:58.267 INFO  TrancheManager -   VQSLODTranche threshold 8.00 => selection metric threshold 0.920
15:06:58.273 INFO  TrancheManager -   Found tranche for 8.000: 0.920 threshold starting with variant 68875; running score is 0.114 
15:06:58.273 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=8.0000 known=(44004 @ 2.4829) novel=(18942 @ 2.4147) truthSites(18665 accessible, 16543 called), name=anonymous]
15:06:58.273 INFO  TrancheManager -   VQSLODTranche threshold 6.00 => selection metric threshold 0.940
15:06:58.277 INFO  TrancheManager -   Found tranche for 6.000: 0.940 threshold starting with variant 34094; running score is 0.052 
15:06:58.278 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=6.0000 known=(52474 @ 2.4242) novel=(45253 @ 2.3994) truthSites(18665 accessible, 17701 called), name=anonymous]
15:06:58.278 INFO  TrancheManager -   VQSLODTranche threshold 4.00 => selection metric threshold 0.960
15:06:58.282 INFO  TrancheManager -   Found tranche for 4.000: 0.960 threshold starting with variant 12275; running score is 0.023 
15:06:58.282 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=4.0000 known=(56181 @ 2.3913) novel=(63365 @ 2.3212) truthSites(18665 accessible, 18243 called), name=anonymous]
15:06:58.282 INFO  TrancheManager -   VQSLODTranche threshold 2.00 => selection metric threshold 0.980
15:06:58.287 INFO  TrancheManager -   Found tranche for 2.000: 0.980 threshold starting with variant 4952; running score is 0.009 
15:06:58.287 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=2.0000 known=(57758 @ 2.3573) novel=(69111 @ 2.2722) truthSites(18665 accessible, 18502 called), name=anonymous]
15:06:58.287 INFO  TrancheManager -   VQSLODTranche threshold 0.00 => selection metric threshold 1.000
15:06:58.292 INFO  TrancheManager -   Found tranche for 0.000: 1.000 threshold starting with variant 2260; running score is 0.004 
15:06:58.292 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=0.0000 known=(58579 @ 2.3306) novel=(70982 @ 2.2511) truthSites(18665 accessible, 18598 called), name=anonymous]
15:06:58.292 INFO  TrancheManager -   VQSLODTranche threshold -2.00 => selection metric threshold 1.020
15:06:58.297 INFO  TrancheManager -   Found tranche for -2.000: 1.020 threshold starting with variant 1099; running score is 0.001 
15:06:58.297 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-2.0000 known=(59019 @ 2.3111) novel=(71703 @ 2.2372) truthSites(18665 accessible, 18640 called), name=anonymous]
15:06:58.297 INFO  TrancheManager -   VQSLODTranche threshold -4.00 => selection metric threshold 1.040
15:06:58.302 INFO  TrancheManager -   Found tranche for -4.000: 1.040 threshold starting with variant 606; running score is 0.001 
15:06:58.302 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-4.0000 known=(59205 @ 2.3054) novel=(72010 @ 2.2272) truthSites(18665 accessible, 18648 called), name=anonymous]
15:06:58.302 INFO  TrancheManager -   VQSLODTranche threshold -6.00 => selection metric threshold 1.060
15:06:58.307 INFO  TrancheManager -   Found tranche for -6.000: 1.060 threshold starting with variant 429; running score is 0.001 
15:06:58.307 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-6.0000 known=(59292 @ 2.3026) novel=(72100 @ 2.2261) truthSites(18665 accessible, 18653 called), name=anonymous]
15:06:58.307 INFO  TrancheManager -   VQSLODTranche threshold -8.00 => selection metric threshold 1.080
15:06:58.311 INFO  TrancheManager -   Found tranche for -8.000: 1.080 threshold starting with variant 314; running score is 0.000 
15:06:58.312 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-8.0000 known=(59355 @ 2.3009) novel=(72152 @ 2.2247) truthSites(18665 accessible, 18657 called), name=anonymous]
15:06:58.312 INFO  TrancheManager -   VQSLODTranche threshold -10.00 => selection metric threshold 1.100
15:06:58.316 INFO  TrancheManager -   Found tranche for -10.000: 1.100 threshold starting with variant 264; running score is 0.000 
15:06:58.316 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-10.0000 known=(59372 @ 2.3008) novel=(72185 @ 2.2246) truthSites(18665 accessible, 18658 called), name=anonymous]
15:06:58.316 INFO  TrancheManager -   VQSLODTranche threshold -12.00 => selection metric threshold 1.120
15:06:58.321 INFO  TrancheManager -   Found tranche for -12.000: 1.120 threshold starting with variant 211; running score is 0.000 
15:06:58.321 INFO  TrancheManager -   VQSLODTranche is Tranche minVQSLod=-12.0000 known=(59394 @ 2.3004) novel=(72216 @ 2.2244) truthSites(18665 accessible, 18659 called), name=anonymous]
15:06:58.321 INFO  VariantRecalibrator - Writing out recalibration table...
15:06:58.622 INFO  VariantRecalibrator - Tranches plot will not be generated since we are running in scattered mode
15:06:58.629 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:06:58 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1107296256
15:06:58.652 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 3:07:00 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1107296256
15:07:00.032 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:00.033 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:07:00.033 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:07:00.033 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:07:00.033 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:07:00.033 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:07:00 PM UTC
15:07:00.033 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:00.033 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:00.033 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:07:00.033 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:07:00.033 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:07:00.033 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:07:00.033 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:07:00.033 INFO  VariantRecalibrator - Inflater: IntelInflater
15:07:00.033 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:07:00.033 INFO  VariantRecalibrator - Requester pays: disabled
15:07:00.033 INFO  VariantRecalibrator - Initializing engine
15:07:00.035 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:07:00.046 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:07:00.084 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:07:00.099 INFO  VariantRecalibrator - Done initializing engine
15:07:00.100 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:07:00.111 INFO  ProgressMeter - Starting traversal
15:07:00.111 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:07:00.168 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        2990357.1
15:07:00.169 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:07:00.169 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:07:00.169 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:07:00.169 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:07:00.169 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:07:00.169 INFO  VariantDataManager - AS_FS: 	 mean = 1.08	 standard deviation = 2.43
15:07:00.170 INFO  VariantDataManager - AS_MQRankSum: 	 mean = 0.00	 standard deviation = 0.01
15:07:00.171 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR, AS_FS, AS_MQRankSum]
15:07:00.171 INFO  VariantDataManager - Training with 2769 variants after standard deviation thresholding.
15:07:00.171 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:07:00.207 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:07:00.232 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.56007
15:07:00.258 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.67355
15:07:00.284 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 5.08559
15:07:00.311 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.01567
15:07:00.338 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.02021
15:07:00.364 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.01989
15:07:00.390 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.02504
15:07:00.417 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03657
15:07:00.443 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.04057
15:07:00.469 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.08648
15:07:00.496 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.01514
15:07:00.522 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00496
15:07:00.548 INFO  VariantRecalibratorEngine - Finished iteration 65. 	Current change in mixture coefficients = 0.00163
15:07:00.548 INFO  VariantRecalibratorEngine - Convergence after 65 iterations!
15:07:00.551 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:07:00.570 INFO  VariantDataManager - Selected worst 5 scoring variants --> variants with LOD <= -5.0000.
15:07:00.570 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:07:00.570 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:07:00.570 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:07:00.570 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:07:00.589 INFO  TrancheManager - Finding 4 tranches for 2786 variants
15:07:00.589 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:07:00.590 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:07:00.590 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:07:00.590 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:07:00.590 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
15:07:00.590 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:07:00.590 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:07:00.590 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
15:07:00.590 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:07:00.590 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:07:00.590 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
15:07:00.591 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:07:00.591 INFO  VariantRecalibrator - Writing out recalibration table...
15:07:00.606 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:07:00 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1107296256
15:07:00.607 INFO  gatk - Initializing VQSR tests/resetting random number generator
[May 27, 2025 at 3:07:02 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.04 minutes.
Runtime.totalMemory()=1107296256
[May 27, 2025 at 3:07:03 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1107296256
[May 27, 2025 at 3:07:03 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1107296256
[May 27, 2025 at 3:07:03 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.00 minutes.
Runtime.totalMemory()=1107296256
[May 27, 2025 at 3:07:04 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1107296256
[May 27, 2025 at 3:07:05 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1107296256
15:07:05.692 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:05.692 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:07:05.692 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:07:05.693 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:07:05.693 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:07:05.693 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:07:05 PM UTC
15:07:05.693 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:05.693 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:05.693 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:07:05.693 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:07:05.694 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:07:05.694 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:07:05.694 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:07:05.694 INFO  VariantRecalibrator - Inflater: IntelInflater
15:07:05.694 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:07:05.694 INFO  VariantRecalibrator - Requester pays: disabled
15:07:05.694 INFO  VariantRecalibrator - Initializing engine
15:07:05.695 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:07:05.698 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:07:05.699 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:07:05.700 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:07:05.702 INFO  IntervalArgumentCollection - Processing 9000001 bp from intervals
15:07:05.703 INFO  VariantRecalibrator - Done initializing engine
15:07:05.703 INFO  TrainingSet - Found known track: 	Known = true 	Training = false 	Truth = false 	Prior = Q10.0
15:07:05.703 INFO  TrainingSet - Found truth_training1 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:07:05.703 INFO  TrainingSet - Found truth_training2 track: 	Known = false 	Training = true 	Truth = true 	Prior = Q12.0
15:07:05.704 INFO  ProgressMeter - Starting traversal
15:07:05.704 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:07:06.649 INFO  ProgressMeter -           20:9944766              0.0                131821        8369587.3
15:07:06.649 INFO  ProgressMeter - Traversal complete. Processed 131821 total variants in 0.0 minutes.
15:07:06.651 INFO  VariantDataManager - QD: 	 mean = 16.58	 standard deviation = 5.43
15:07:06.655 INFO  VariantDataManager - HaplotypeScore: 	 mean = 0.27	 standard deviation = 0.27
15:07:06.657 INFO  VariantDataManager - HRun: 	 mean = 0.59	 standard deviation = 0.99
15:07:06.675 INFO  VariantDataManager - Annotation order is: [QD, HRun, HaplotypeScore]
15:07:06.676 INFO  VariantDataManager - Training with 18642 variants after standard deviation thresholding.
15:07:06.676 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:07:06.929 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:07:07.040 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.42302
15:07:07.152 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.24203
15:07:07.265 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.15214
15:07:07.381 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.22858
15:07:07.497 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.07799
15:07:07.612 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.04227
15:07:07.729 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00976
15:07:07.847 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.03859
15:07:07.942 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.18953
15:07:08.038 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.01049
15:07:08.114 INFO  VariantRecalibratorEngine - Convergence after 54 iterations!
15:07:08.121 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:07:08.194 INFO  VariantDataManager - Selected worst 474 scoring variants --> variants with LOD <= -5.0000.
15:07:08.194 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:07:08.195 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:07:08.196 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:07:08.197 INFO  VariantRecalibratorEngine - Evaluating full set of 131821 variants...
15:07:08.381 INFO  TrancheManager - Finding 12 tranches for 131821 variants
15:07:08.412 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:07:08.417 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:07:08.417 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:07:08.417 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
15:07:08.421 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 381; running score is 0.001 
15:07:08.421 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:07:08.421 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:07:08.426 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 747; running score is 0.001 
15:07:08.426 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:07:08.426 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
15:07:08.431 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 1480; running score is 0.002 
15:07:08.431 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:07:08.431 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
15:07:08.435 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 2377; running score is 0.004 
15:07:08.435 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:07:08.435 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
15:07:08.441 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 3042; running score is 0.005 
15:07:08.441 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:07:08.441 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
15:07:08.446 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 3577; running score is 0.006 
15:07:08.446 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:07:08.446 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
15:07:08.450 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 4004; running score is 0.007 
15:07:08.450 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:07:08.450 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:07:08.455 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 5604; running score is 0.010 
15:07:08.455 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:07:08.455 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
15:07:08.460 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 10673; running score is 0.020 
15:07:08.460 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:07:08.460 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
15:07:08.467 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 16985; running score is 0.030 
15:07:08.467 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:07:08.467 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:07:08.473 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 63492; running score is 0.100 
15:07:08.473 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:07:08.474 INFO  VariantRecalibrator - Writing out recalibration table...
15:07:08.771 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:07:08 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.05 minutes.
Runtime.totalMemory()=1107296256
15:07:08.802 INFO  gatk - Initializing VQSR tests/resetting random number generator
15:07:08.810 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:08.810 INFO  VariantRecalibrator - org.broadinstitute.hellbender.tools.walkers.vqsr vUnavailable
15:07:08.810 INFO  VariantRecalibrator - For support and documentation go to https://software.broadinstitute.org/gatk/
15:07:08.810 INFO  VariantRecalibrator - Executing as runner@pkrvmf6wy0o8zjz on Linux v6.11.0-1014-azure amd64
15:07:08.810 INFO  VariantRecalibrator - Java runtime: OpenJDK 64-Bit Server VM v17.0.6+10
15:07:08.810 INFO  VariantRecalibrator - Start Date/Time: May 27, 2025 at 3:07:08 PM UTC
15:07:08.810 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:08.810 INFO  VariantRecalibrator - ------------------------------------------------------------
15:07:08.811 INFO  VariantRecalibrator - HTSJDK Defaults.COMPRESSION_LEVEL : 2
15:07:08.811 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false
15:07:08.811 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true
15:07:08.811 INFO  VariantRecalibrator - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false
15:07:08.811 INFO  VariantRecalibrator - Deflater: IntelDeflater
15:07:08.811 INFO  VariantRecalibrator - Inflater: IntelInflater
15:07:08.811 INFO  VariantRecalibrator - GCS max retries/reopens: 20
15:07:08.811 INFO  VariantRecalibrator - Requester pays: disabled
15:07:08.811 INFO  VariantRecalibrator - Initializing engine
15:07:08.812 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:07:08.823 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:07:08.856 INFO  IntervalArgumentCollection - Processing 10000000 bp from intervals
15:07:08.869 INFO  VariantRecalibrator - Done initializing engine
15:07:08.869 INFO  TrainingSet - Found same track: 	Known = false 	Training = true 	Truth = true 	Prior = Q15.0
15:07:08.879 INFO  ProgressMeter - Starting traversal
15:07:08.879 INFO  ProgressMeter -        Current Locus  Elapsed Minutes    Variants Processed  Variants/Minute
15:07:08.934 INFO  ProgressMeter -         chr1:6212018              0.0                  2791        3044727.3
15:07:08.935 INFO  ProgressMeter - Traversal complete. Processed 2791 total variants in 0.0 minutes.
15:07:08.935 INFO  VariantDataManager - AS_QD: 	 mean = 20.88	 standard deviation = 8.12
15:07:08.935 INFO  VariantDataManager - AS_ReadPosRankSum: 	 mean = -0.05	 standard deviation = 0.74
15:07:08.935 INFO  VariantDataManager - AS_MQ: 	 mean = 59.82	 standard deviation = 2.48
15:07:08.935 INFO  VariantDataManager - AS_SOR: 	 mean = 0.86	 standard deviation = 0.67
15:07:08.936 INFO  VariantDataManager - Annotation order is: [AS_QD, AS_ReadPosRankSum, AS_MQ, AS_SOR]
15:07:08.936 INFO  VariantDataManager - Training with 2774 variants after standard deviation thresholding.
15:07:08.936 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:07:08.966 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:07:08.983 INFO  VariantRecalibratorEngine - Finished iteration 5. 	Current change in mixture coefficients = 0.12046
15:07:09.001 INFO  VariantRecalibratorEngine - Finished iteration 10. 	Current change in mixture coefficients = 0.09714
15:07:09.018 INFO  VariantRecalibratorEngine - Finished iteration 15. 	Current change in mixture coefficients = 0.07781
15:07:09.035 INFO  VariantRecalibratorEngine - Finished iteration 20. 	Current change in mixture coefficients = 0.05863
15:07:09.053 INFO  VariantRecalibratorEngine - Finished iteration 25. 	Current change in mixture coefficients = 0.01774
15:07:09.070 INFO  VariantRecalibratorEngine - Finished iteration 30. 	Current change in mixture coefficients = 0.00612
15:07:09.087 INFO  VariantRecalibratorEngine - Finished iteration 35. 	Current change in mixture coefficients = 0.00395
15:07:09.105 INFO  VariantRecalibratorEngine - Finished iteration 40. 	Current change in mixture coefficients = 0.00313
15:07:09.122 INFO  VariantRecalibratorEngine - Finished iteration 45. 	Current change in mixture coefficients = 0.00276
15:07:09.140 INFO  VariantRecalibratorEngine - Finished iteration 50. 	Current change in mixture coefficients = 0.00245
15:07:09.157 INFO  VariantRecalibratorEngine - Finished iteration 55. 	Current change in mixture coefficients = 0.00219
15:07:09.175 INFO  VariantRecalibratorEngine - Finished iteration 60. 	Current change in mixture coefficients = 0.00198
15:07:09.175 INFO  VariantRecalibratorEngine - Convergence after 60 iterations!
15:07:09.176 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:07:09.185 INFO  VariantDataManager - Selected worst 6 scoring variants --> variants with LOD <= -5.0000.
15:07:09.185 INFO  GaussianMixtureModel - Initializing model with 100 k-means iterations...
15:07:09.185 INFO  VariantRecalibratorEngine - Finished iteration 0.
15:07:09.185 INFO  VariantRecalibratorEngine - Convergence after 3 iterations!
15:07:09.185 INFO  VariantRecalibratorEngine - Evaluating full set of 2786 variants...
15:07:09.193 INFO  TrancheManager - Finding 12 tranches for 2786 variants
15:07:09.194 INFO  TrancheManager -   TruthSensitivityTranche threshold 100.00 => selection metric threshold 0.000
15:07:09.194 INFO  TrancheManager -   Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 
15:07:09.194 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:07:09.194 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.95 => selection metric threshold 0.000
15:07:09.194 INFO  TrancheManager -   Found tranche for 99.950: 0.000 threshold starting with variant 2; running score is 0.001 
15:07:09.195 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:07:09.195 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.90 => selection metric threshold 0.001
15:07:09.195 INFO  TrancheManager -   Found tranche for 99.900: 0.001 threshold starting with variant 3; running score is 0.001 
15:07:09.195 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:07:09.195 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.80 => selection metric threshold 0.002
15:07:09.195 INFO  TrancheManager -   Found tranche for 99.800: 0.002 threshold starting with variant 6; running score is 0.002 
15:07:09.195 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:07:09.195 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.60 => selection metric threshold 0.004
15:07:09.195 INFO  TrancheManager -   Found tranche for 99.600: 0.004 threshold starting with variant 12; running score is 0.004 
15:07:09.195 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:07:09.195 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.50 => selection metric threshold 0.005
15:07:09.196 INFO  TrancheManager -   Found tranche for 99.500: 0.005 threshold starting with variant 14; running score is 0.005 
15:07:09.196 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:07:09.196 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.40 => selection metric threshold 0.006
15:07:09.196 INFO  TrancheManager -   Found tranche for 99.400: 0.006 threshold starting with variant 17; running score is 0.006 
15:07:09.196 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:07:09.196 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.30 => selection metric threshold 0.007
15:07:09.196 INFO  TrancheManager -   Found tranche for 99.300: 0.007 threshold starting with variant 20; running score is 0.007 
15:07:09.196 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:07:09.196 INFO  TrancheManager -   TruthSensitivityTranche threshold 99.00 => selection metric threshold 0.010
15:07:09.197 INFO  TrancheManager -   Found tranche for 99.000: 0.010 threshold starting with variant 28; running score is 0.010 
15:07:09.197 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:07:09.197 INFO  TrancheManager -   TruthSensitivityTranche threshold 98.00 => selection metric threshold 0.020
15:07:09.197 INFO  TrancheManager -   Found tranche for 98.000: 0.020 threshold starting with variant 56; running score is 0.020 
15:07:09.197 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:07:09.197 INFO  TrancheManager -   TruthSensitivityTranche threshold 97.00 => selection metric threshold 0.030
15:07:09.197 INFO  TrancheManager -   Found tranche for 97.000: 0.030 threshold starting with variant 84; running score is 0.030 
15:07:09.197 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:07:09.197 INFO  TrancheManager -   TruthSensitivityTranche threshold 90.00 => selection metric threshold 0.100
15:07:09.197 INFO  TrancheManager -   Found tranche for 90.000: 0.100 threshold starting with variant 279; running score is 0.100 
15:07:09.197 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:07:09.198 INFO  VariantRecalibrator - Writing out recalibration table...
15:07:09.214 INFO  VariantRecalibrator - Shutting down engine
[May 27, 2025 at 3:07:09 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.01 minutes.
Runtime.totalMemory()=1107296256
[May 27, 2025 at 3:08:15 PM UTC] org.broadinstitute.hellbender.tools.walkers.vqsr.VariantRecalibrator done. Elapsed time: 0.02 minutes.
Runtime.totalMemory()=1839202304