# Base command line, one time with QD and another w/o $JAVA_1_7/java -jar $GATK_DIR/GenomeAnalysisTK.jar \ -T VariantRecalibrator \ -R $REF_GENOME \ --input:VCF $CORE_PATH/$PROJECT/MULTI_SAMPLE/$PREFIX".raw.HC.SNV.vcf" \ -resource:hapmap,known=false,training=true,truth=true,prior=15.0 /isilon/sequencing/GATK_resource_bundle/2.5/b37/hapmap_3.3.b37.vcf \ -resource:omni,known=false,training=true,truth=true,prior=12.0 /isilon/sequencing/GATK_resource_bundle/2.5/b37/1000G_omni2.5.b37.vcf \ -resource:1000G,known=false,training=true,truth=false,prior=10.0 /isilon/sequencing/GATK_resource_bundle/2.5/b37/1000G_phase1.snps.high_confidence.b37.vcf \ -resource:dbsnp,known=true,training=false,truth=false,prior=2.0 /isilon/sequencing/GATK_resource_bundle/2.8/b37/dbsnp_138.b37.vcf \ -mode SNP \ -an QD \ -an MQRankSum \ -an ReadPosRankSum \ -an FS \ -tranche 100.0 \ -tranche 99.9 \ -tranche 99.8 \ -tranche 99.7 \ -tranche 99.6 \ -tranche 99.5 \ -tranche 99.4 \ -tranche 99.3 \ -tranche 99.2 \ -tranche 99.1 \ -tranche 99.0 \ -tranche 98.0 \ -tranche 97.0 \ -tranche 96.0 \ -tranche 95.0 \ -tranche 90.0 \ -recalFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/$PREFIX".HC.SNV.recal" \ -tranchesFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/$PREFIX".HC.SNV.tranches" \ -rscriptFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/$PREFIX".HC.SNV.R" >>>> # This is a run with QD added into the model. It tries to train 0 worst variants and then goes boom. INFO 12:46:48,644 HelpFormatter - -------------------------------------------------------------------------------- INFO 12:46:48,689 HelpFormatter - The Genome Analysis Toolkit (GATK) v3.1-1-g07a4bf8, Compiled 2014/03/18 06:09:21 INFO 12:46:48,689 HelpFormatter - Copyright (c) 2010 The Broad Institute INFO 12:46:48,689 HelpFormatter - For support and documentation go to http://www.broadinstitute.org/gatk INFO 12:46:48,693 HelpFormatter - Program Args: -T VariantRecalibrator -R /isilon/sequencing/GATK_resource_bundle/1.5/b37/human_g1k_v37_decoy.fasta --input:VCF /isilon/sequencing/Seq_Proj//M_Valle_MendelianDisorders_SeqWholeExome_120511_GATK_3_1-1/MULTI_SAMPLE /Mendel.1.to.22.Partial.raw.HC.SNV.vcf -resource:hapmap,known=false,training=true,truth=true,prior=15.0 /isilon/sequencing/GATK_resource_bundle/2.5/b37/hapmap_3.3.b37.vcf -resource:omni,known=false,training=true,truth=true,prior=12.0 /isilon/sequencing/GATK_res ource_bundle/2.5/b37/1000G_omni2.5.b37.vcf -resource:1000G,known=false,training=true,truth=false,prior=10.0 /isilon/sequencing/GATK_resource_bundle/2.5/b37/1000G_phase1.snps.high_confidence.b37.vcf -resource:dbsnp,known=true,training=false,truth=false,prior=2.0 /isilon/sequencing/GATK_resource_bundle/2.8/b37/dbsnp_138.b37.vcf -mode SNP -an QD -an MQ -an MQRankSum -an ReadPosRankSum -an FS -tranche 100.0 -tranche 99.9 -tranche 99.8 -tranche 99.7 -tranche 99.6 -tranche 99.5 -tranche 99.4 -tranche 99.3 -tranche 99.2 -tr anche 99.1 -tranche 99.0 -tranche 98.0 -tranche 97.0 -tranche 96.0 -tranche 95.0 -tranche 90.0 -recalFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1.to.22.Partial.HC.SNV.recal -tranchesFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1. to.22.Partial.HC.SNV.tranches -rscriptFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1.to.22.Partial.HC.SNV.R INFO 12:46:53,704 HelpFormatter - Executing as khetrick@sunrhel4.cidr.jhmi.edu on Linux 2.6.32-220.el6.x86_64 amd64; Java HotSpot(TM) 64-Bit Server VM 1.7.0_25-b15. INFO 12:46:53,705 HelpFormatter - Date/Time: 2014/06/10 12:46:48 INFO 12:46:53,705 HelpFormatter - -------------------------------------------------------------------------------- INFO 12:46:53,705 HelpFormatter - -------------------------------------------------------------------------------- INFO 12:46:54,458 GenomeAnalysisEngine - Strictness is SILENT INFO 12:46:54,667 GenomeAnalysisEngine - Downsampling Settings: Method: BY_SAMPLE, Target Coverage: 1000 INFO 12:46:55,621 GenomeAnalysisEngine - Preparing for traversal INFO 12:46:55,638 GenomeAnalysisEngine - Done preparing for traversal INFO 12:46:55,638 ProgressMeter - [INITIALIZATION COMPLETE; STARTING PROCESSING] INFO 12:46:55,639 ProgressMeter - Location processed.sites runtime per.1M.sites completed total.runtime remaining INFO 12:46:55,664 TrainingSet - Found hapmap track: Known = false Training = true Truth = true Prior = Q15.0 INFO 12:46:55,664 TrainingSet - Found omni track: Known = false Training = true Truth = true Prior = Q12.0 INFO 12:46:55,665 TrainingSet - Found 1000G track: Known = false Training = true Truth = false Prior = Q10.0 INFO 12:46:55,665 TrainingSet - Found dbsnp track: Known = true Training = false Truth = false Prior = Q2.0 INFO 12:47:25,645 ProgressMeter - 1:91735510 2.13e+06 30.0 s 14.0 s 2.9% 17.1 m 16.6 m INFO 12:47:55,648 ProgressMeter - 1:215655522 4.47e+06 60.0 s 13.0 s 6.9% 14.5 m 13.5 m INFO 12:48:25,650 ProgressMeter - 2:52013433 6.61e+06 90.0 s 13.0 s 9.6% 15.6 m 14.1 m INFO 12:48:55,651 ProgressMeter - 2:165026042 9.10e+06 120.0 s 13.0 s 13.2% 15.1 m 13.1 m INFO 12:49:25,653 ProgressMeter - 3:21933398 1.15e+07 2.5 m 13.0 s 16.4% 15.2 m 12.7 m INFO 12:49:55,655 ProgressMeter - 3:129156563 1.39e+07 3.0 m 12.0 s 19.8% 15.1 m 12.1 m INFO 12:50:25,657 ProgressMeter - 4:33000075 1.64e+07 3.5 m 12.0 s 23.1% 15.2 m 11.7 m INFO 12:50:55,658 ProgressMeter - 4:145091280 1.90e+07 4.0 m 12.0 s 26.6% 15.0 m 11.0 m INFO 12:51:25,660 ProgressMeter - 5:60240119 2.15e+07 4.5 m 12.0 s 30.0% 15.0 m 10.5 m INFO 12:51:55,662 ProgressMeter - 5:169604366 2.40e+07 5.0 m 12.0 s 33.5% 14.9 m 9.9 m INFO 12:52:25,663 ProgressMeter - 6:86206029 2.64e+07 5.5 m 12.0 s 36.6% 15.0 m 9.5 m INFO 12:52:55,665 ProgressMeter - 7:15771587 2.89e+07 6.0 m 12.0 s 39.8% 15.1 m 9.1 m INFO 12:53:25,667 ProgressMeter - 7:125870007 3.14e+07 6.5 m 12.0 s 43.3% 15.0 m 8.5 m INFO 12:53:55,668 ProgressMeter - 8:59997803 3.38e+07 7.0 m 12.0 s 46.3% 15.1 m 8.1 m INFO 12:54:25,669 ProgressMeter - 9:15781082 3.63e+07 7.5 m 12.0 s 49.6% 15.1 m 7.6 m INFO 12:54:55,764 ProgressMeter - 10:2987208 3.88e+07 8.0 m 12.0 s 53.7% 14.9 m 6.9 m INFO 12:55:25,765 ProgressMeter - 10:111772692 4.13e+07 8.5 m 12.0 s 57.1% 14.9 m 6.4 m INFO 12:55:55,767 ProgressMeter - 11:70486996 4.36e+07 9.0 m 12.0 s 60.1% 15.0 m 6.0 m INFO 12:56:25,768 ProgressMeter - 12:43798010 4.62e+07 9.5 m 12.0 s 63.6% 14.9 m 5.4 m INFO 12:56:55,770 ProgressMeter - 13:27653117 4.86e+07 10.0 m 12.0 s 67.3% 14.9 m 4.9 m INFO 12:57:25,771 ProgressMeter - 14:37376762 5.11e+07 10.5 m 12.0 s 71.3% 14.7 m 4.2 m INFO 12:57:55,773 ProgressMeter - 15:53999125 5.35e+07 11.0 m 12.0 s 75.3% 14.6 m 3.6 m INFO 12:58:25,774 ProgressMeter - 16:57691351 5.59e+07 11.5 m 12.0 s 78.6% 14.6 m 3.1 m INFO 12:58:55,776 ProgressMeter - 17:58862869 5.83e+07 12.0 m 12.0 s 81.6% 14.7 m 2.7 m INFO 12:59:25,777 ProgressMeter - 19:621039 6.07e+07 12.5 m 12.0 s 84.8% 14.7 m 2.2 m INFO 12:59:55,779 ProgressMeter - 20:25439089 6.29e+07 13.0 m 12.0 s 87.5% 14.9 m 111.0 s INFO 13:00:25,781 ProgressMeter - 22:38901604 6.54e+07 13.5 m 12.0 s 91.4% 14.8 m 75.0 s INFO 13:00:55,783 ProgressMeter - X:145198627 6.81e+07 14.0 m 12.0 s 96.5% 14.5 m 30.0 s INFO 13:00:59,213 VariantDataManager - QD: mean = 17.15 standard deviation = 4.73 INFO 13:00:59,431 VariantDataManager - MQ: mean = 59.93 standard deviation = 0.85 INFO 13:00:59,635 VariantDataManager - MQRankSum: mean = 0.07 standard deviation = 0.57 INFO 13:00:59,843 VariantDataManager - ReadPosRankSum: mean = 0.55 standard deviation = 0.65 INFO 13:01:00,048 VariantDataManager - FS: mean = 1.74 standard deviation = 3.63 INFO 13:01:01,116 VariantDataManager - Annotations are now ordered by their information content: [MQ, QD, FS, ReadPosRankSum, MQRankSum] INFO 13:01:01,192 VariantDataManager - Training with 374495 variants after standard deviation thresholding. INFO 13:01:01,197 GaussianMixtureModel - Initializing model with 100 k-means iterations... INFO 13:01:25,784 ProgressMeter - GL000202.1:10465 6.85e+07 14.5 m 12.0 s 98.7% 14.7 m 11.0 s INFO 13:01:55,786 ProgressMeter - GL000202.1:10465 6.85e+07 15.0 m 13.0 s 98.7% 15.2 m 11.0 s INFO 13:02:03,321 VariantRecalibratorEngine - Finished iteration 0. INFO 13:02:24,766 VariantRecalibratorEngine - Finished iteration 5. Current change in mixture coefficients = 0.78672 INFO 13:02:25,787 ProgressMeter - GL000202.1:10465 6.85e+07 15.5 m 13.0 s 98.7% 15.7 m 12.0 s INFO 13:02:45,913 VariantRecalibratorEngine - Finished iteration 10. Current change in mixture coefficients = 0.32772 INFO 13:02:55,789 ProgressMeter - GL000202.1:10465 6.85e+07 16.0 m 14.0 s 98.7% 16.2 m 12.0 s INFO 13:03:06,477 VariantRecalibratorEngine - Finished iteration 15. Current change in mixture coefficients = 0.14209 INFO 13:03:25,790 ProgressMeter - GL000202.1:10465 6.85e+07 16.5 m 14.0 s 98.7% 16.7 m 13.0 s INFO 13:03:27,713 VariantRecalibratorEngine - Finished iteration 20. Current change in mixture coefficients = 0.17621 INFO 13:03:48,244 VariantRecalibratorEngine - Finished iteration 25. Current change in mixture coefficients = 0.35577 INFO 13:03:55,792 ProgressMeter - GL000202.1:10465 6.85e+07 17.0 m 14.0 s 98.7% 17.2 m 13.0 s INFO 13:04:09,617 VariantRecalibratorEngine - Finished iteration 30. Current change in mixture coefficients = 0.30291 INFO 13:04:25,793 ProgressMeter - GL000202.1:10465 6.85e+07 17.5 m 15.0 s 98.7% 17.7 m 13.0 s INFO 13:04:30,197 VariantRecalibratorEngine - Finished iteration 35. Current change in mixture coefficients = 0.34596 INFO 13:04:50,707 VariantRecalibratorEngine - Finished iteration 40. Current change in mixture coefficients = 0.05769 INFO 13:04:55,925 ProgressMeter - GL000202.1:10465 6.85e+07 18.0 m 15.0 s 98.7% 18.2 m 14.0 s INFO 13:05:11,398 VariantRecalibratorEngine - Finished iteration 45. Current change in mixture coefficients = 0.04344 INFO 13:05:25,926 ProgressMeter - GL000202.1:10465 6.85e+07 18.5 m 16.0 s 98.7% 18.7 m 14.0 s INFO 13:05:32,761 VariantRecalibratorEngine - Finished iteration 50. Current change in mixture coefficients = 0.02785 INFO 13:05:54,172 VariantRecalibratorEngine - Finished iteration 55. Current change in mixture coefficients = 0.01666 INFO 13:05:55,928 ProgressMeter - GL000202.1:10465 6.85e+07 19.0 m 16.0 s 98.7% 19.3 m 15.0 s INFO 13:06:15,348 VariantRecalibratorEngine - Finished iteration 60. Current change in mixture coefficients = 0.00996 INFO 13:06:25,929 ProgressMeter - GL000202.1:10465 6.85e+07 19.5 m 17.0 s 98.7% 19.8 m 15.0 s INFO 13:06:36,453 VariantRecalibratorEngine - Finished iteration 65. Current change in mixture coefficients = 0.00612 INFO 13:06:55,931 ProgressMeter - GL000202.1:10465 6.85e+07 20.0 m 17.0 s 98.7% 20.3 m 15.0 s INFO 13:06:57,703 VariantRecalibratorEngine - Finished iteration 70. Current change in mixture coefficients = 0.00396 INFO 13:07:19,014 VariantRecalibratorEngine - Finished iteration 75. Current change in mixture coefficients = 0.00279 INFO 13:07:25,932 ProgressMeter - GL000202.1:10465 6.85e+07 20.5 m 17.0 s 98.7% 20.8 m 16.0 s INFO 13:07:39,836 VariantRecalibratorEngine - Finished iteration 80. Current change in mixture coefficients = 0.00238 INFO 13:07:55,934 ProgressMeter - GL000202.1:10465 6.85e+07 21.0 m 18.0 s 98.7% 21.3 m 16.0 s INFO 13:08:00,231 VariantRecalibratorEngine - Finished iteration 85. Current change in mixture coefficients = 0.00289 INFO 13:08:20,769 VariantRecalibratorEngine - Finished iteration 90. Current change in mixture coefficients = 0.00386 INFO 13:08:25,936 ProgressMeter - GL000202.1:10465 6.85e+07 21.5 m 18.0 s 98.7% 21.8 m 17.0 s INFO 13:08:41,283 VariantRecalibratorEngine - Finished iteration 95. Current change in mixture coefficients = 0.00380 INFO 13:08:55,938 ProgressMeter - GL000202.1:10465 6.85e+07 22.0 m 19.0 s 98.7% 22.3 m 17.0 s INFO 13:09:01,834 VariantRecalibratorEngine - Finished iteration 100. Current change in mixture coefficients = 0.00545 INFO 13:09:22,165 VariantRecalibratorEngine - Finished iteration 105. Current change in mixture coefficients = 0.02816 INFO 13:09:25,939 ProgressMeter - GL000202.1:10465 6.85e+07 22.5 m 19.0 s 98.7% 22.8 m 17.0 s INFO 13:09:41,986 VariantRecalibratorEngine - Finished iteration 110. Current change in mixture coefficients = 0.00454 INFO 13:09:53,866 VariantRecalibratorEngine - Convergence after 113 iterations! INFO 13:09:55,941 ProgressMeter - GL000202.1:10465 6.85e+07 23.0 m 20.0 s 98.7% 23.3 m 18.0 s INFO 13:09:56,491 VariantRecalibratorEngine - Evaluating full set of 827861 variants... INFO 13:09:56,557 VariantDataManager - Training with worst 0 scoring variants --> variants with LOD <= -5.0000. INFO 13:10:05,539 GATKRunReport - Uploaded run statistics report to AWS S3 ##### ERROR ------------------------------------------------------------------------------------------ ##### ERROR stack trace java.lang.IllegalArgumentException: No data found. at org.broadinstitute.sting.gatk.walkers.variantrecalibration.VariantRecalibratorEngine.generateModel(VariantRecalibratorEngine.java:83) at org.broadinstitute.sting.gatk.walkers.variantrecalibration.VariantRecalibrator.onTraversalDone(VariantRecalibrator.java:392) at org.broadinstitute.sting.gatk.walkers.variantrecalibration.VariantRecalibrator.onTraversalDone(VariantRecalibrator.java:138) at org.broadinstitute.sting.gatk.executive.Accumulator$StandardAccumulator.finishTraversal(Accumulator.java:129) at org.broadinstitute.sting.gatk.executive.LinearMicroScheduler.execute(LinearMicroScheduler.java:116) at org.broadinstitute.sting.gatk.GenomeAnalysisEngine.execute(GenomeAnalysisEngine.java:313) at org.broadinstitute.sting.gatk.CommandLineExecutable.execute(CommandLineExecutable.java:121) at org.broadinstitute.sting.commandline.CommandLineProgram.start(CommandLineProgram.java:248) at org.broadinstitute.sting.commandline.CommandLineProgram.start(CommandLineProgram.java:155) at org.broadinstitute.sting.gatk.CommandLineGATK.main(CommandLineGATK.java:107) ##### ERROR ------------------------------------------------------------------------------------------ ##### ERROR A GATK RUNTIME ERROR has occurred (version 3.1-1-g07a4bf8): ##### ERROR ##### ERROR This might be a bug. Please check the documentation guide to see if this is a known problem. ##### ERROR If not, please post the error message, with stack trace, to the GATK forum. ##### ERROR Visit our website and forum for extensive documentation and answers to ##### ERROR commonly asked questions http://www.broadinstitute.org/gatk ##### ERROR ##### ERROR MESSAGE: No data found. ##### ERROR ------------------------------------------------------------------------------------------ >>> # This is the exact same data set but now w/o including MQ INFO 13:26:08,810 HelpFormatter - -------------------------------------------------------------------------------- INFO 13:26:08,815 HelpFormatter - The Genome Analysis Toolkit (GATK) v3.1-1-g07a4bf8, Compiled 2014/03/18 06:09:21 INFO 13:26:08,815 HelpFormatter - Copyright (c) 2010 The Broad Institute INFO 13:26:08,815 HelpFormatter - For support and documentation go to http://www.broadinstitute.org/gatk INFO 13:26:08,820 HelpFormatter - Program Args: -T VariantRecalibrator -R /isilon/sequencing/GATK_resource_bundle/1.5/b37/human_g1k_v37_decoy.fasta --input:VCF /isilon/sequencing/Seq_Proj//M_Valle_MendelianDisorders_SeqWholeExome_120511_GATK_3_1-1/MULTI_SAMPLE /Mendel.1.to.22.Partial.raw.HC.SNV.vcf -resource:hapmap,known=false,training=true,truth=true,prior=15.0 /isilon/sequencing/GATK_resource_bundle/2.5/b37/hapmap_3.3.b37.vcf -resource:omni,known=false,training=true,truth=true,prior=12.0 /isilon/sequencing/GATK_res ource_bundle/2.5/b37/1000G_omni2.5.b37.vcf -resource:1000G,known=false,training=true,truth=false,prior=10.0 /isilon/sequencing/GATK_resource_bundle/2.5/b37/1000G_phase1.snps.high_confidence.b37.vcf -resource:dbsnp,known=true,training=false,truth=false,prior=2.0 /isilon/sequencing/GATK_resource_bundle/2.8/b37/dbsnp_138.b37.vcf -mode SNP -an QD -an MQRankSum -an ReadPosRankSum -an FS -tranche 100.0 -tranche 99.9 -tranche 99.8 -tranche 99.7 -tranche 99.6 -tranche 99.5 -tranche 99.4 -tranche 99.3 -tranche 99.2 -tranche 9 9.1 -tranche 99.0 -tranche 98.0 -tranche 97.0 -tranche 96.0 -tranche 95.0 -tranche 90.0 -recalFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1.to.22.Partial.HC.SNV.recal -tranchesFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1.to.22.P artial.HC.SNV.tranches -rscriptFile /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1.to.22.Partial.HC.SNV.R INFO 13:26:08,826 HelpFormatter - Executing as khetrick@sunrhel4.cidr.jhmi.edu on Linux 2.6.32-220.el6.x86_64 amd64; Java HotSpot(TM) 64-Bit Server VM 1.7.0_25-b15. INFO 13:26:08,826 HelpFormatter - Date/Time: 2014/06/10 13:26:08 INFO 13:26:08,827 HelpFormatter - -------------------------------------------------------------------------------- INFO 13:26:08,827 HelpFormatter - -------------------------------------------------------------------------------- INFO 13:26:09,456 GenomeAnalysisEngine - Strictness is SILENT INFO 13:26:09,577 GenomeAnalysisEngine - Downsampling Settings: Method: BY_SAMPLE, Target Coverage: 1000 INFO 13:26:10,233 GenomeAnalysisEngine - Preparing for traversal INFO 13:26:10,250 GenomeAnalysisEngine - Done preparing for traversal INFO 13:26:10,250 ProgressMeter - [INITIALIZATION COMPLETE; STARTING PROCESSING] INFO 13:26:10,250 ProgressMeter - Location processed.sites runtime per.1M.sites completed total.runtime remaining INFO 13:26:10,258 TrainingSet - Found hapmap track: Known = false Training = true Truth = true Prior = Q15.0 INFO 13:26:10,259 TrainingSet - Found omni track: Known = false Training = true Truth = true Prior = Q12.0 INFO 13:26:10,259 TrainingSet - Found 1000G track: Known = false Training = true Truth = false Prior = Q10.0 INFO 13:26:10,260 TrainingSet - Found dbsnp track: Known = true Training = false Truth = false Prior = Q2.0 INFO 13:26:40,257 ProgressMeter - 1:96526335 2.24e+06 30.0 s 13.0 s 3.1% 16.3 m 15.8 m INFO 13:27:10,259 ProgressMeter - 1:230483222 4.81e+06 60.0 s 12.0 s 7.3% 13.6 m 12.6 m INFO 13:27:40,261 ProgressMeter - 2:95419595 7.53e+06 90.0 s 11.0 s 11.0% 13.7 m 12.2 m INFO 13:28:10,263 ProgressMeter - 2:217806663 1.02e+07 120.0 s 11.0 s 14.9% 13.4 m 11.4 m INFO 13:28:40,265 ProgressMeter - 3:78588573 1.28e+07 2.5 m 11.0 s 18.2% 13.7 m 11.2 m INFO 13:29:10,267 ProgressMeter - 3:184071548 1.52e+07 3.0 m 11.0 s 21.6% 13.9 m 10.9 m INFO 13:29:40,269 ProgressMeter - 4:82075676 1.76e+07 3.5 m 11.0 s 24.6% 14.2 m 10.7 m INFO 13:30:10,270 ProgressMeter - 4:186457509 1.99e+07 4.0 m 12.0 s 28.0% 14.3 m 10.3 m INFO 13:30:40,272 ProgressMeter - 5:100210829 2.24e+07 4.5 m 12.0 s 31.3% 14.4 m 9.9 m INFO 13:31:10,274 ProgressMeter - 6:14286108 2.47e+07 5.0 m 12.0 s 34.3% 14.6 m 9.6 m INFO 13:31:40,276 ProgressMeter - 6:110421229 2.69e+07 5.5 m 12.0 s 37.4% 14.7 m 9.2 m INFO 13:32:10,278 ProgressMeter - 7:31692238 2.93e+07 6.0 m 12.0 s 40.3% 14.9 m 8.9 m INFO 13:32:40,280 ProgressMeter - 7:138101541 3.17e+07 6.5 m 12.0 s 43.7% 14.9 m 8.4 m INFO 13:33:10,282 ProgressMeter - 8:68815695 3.40e+07 7.0 m 12.0 s 46.6% 15.0 m 8.0 m INFO 13:33:40,283 ProgressMeter - 9:17981114 3.63e+07 7.5 m 12.0 s 49.6% 15.1 m 7.6 m INFO 13:34:10,285 ProgressMeter - 9:141127070 3.87e+07 8.0 m 12.0 s 53.6% 14.9 m 6.9 m INFO 13:34:40,287 ProgressMeter - 10:101518936 4.11e+07 8.5 m 12.0 s 56.8% 15.0 m 6.5 m INFO 13:35:10,288 ProgressMeter - 11:60594257 4.34e+07 9.0 m 12.0 s 59.8% 15.0 m 6.0 m INFO 13:35:40,290 ProgressMeter - 12:18826490 4.56e+07 9.5 m 12.0 s 62.8% 15.1 m 5.6 m INFO 13:36:10,292 ProgressMeter - 12:121030044 4.80e+07 10.0 m 12.0 s 66.0% 15.1 m 5.1 m INFO 13:36:40,293 ProgressMeter - 13:105202336 5.04e+07 10.5 m 12.0 s 69.8% 15.0 m 4.5 m INFO 13:37:10,295 ProgressMeter - 14:104738772 5.27e+07 11.0 m 12.0 s 73.5% 15.0 m 4.0 m INFO 13:37:40,297 ProgressMeter - 16:6225854 5.49e+07 11.5 m 12.0 s 77.0% 14.9 m 3.4 m INFO 13:38:10,299 ProgressMeter - 17:10360085 5.72e+07 12.0 m 12.0 s 80.0% 15.0 m 3.0 m INFO 13:38:40,301 ProgressMeter - 18:27345900 5.95e+07 12.5 m 12.0 s 83.1% 15.0 m 2.5 m INFO 13:39:10,424 ProgressMeter - 19:40428798 6.17e+07 13.0 m 12.0 s 86.1% 15.1 m 2.1 m INFO 13:39:40,426 ProgressMeter - 21:17186609 6.40e+07 13.5 m 12.0 s 89.2% 15.1 m 98.0 s INFO 13:40:10,428 ProgressMeter - X:36062391 6.64e+07 14.0 m 12.0 s 93.0% 15.1 m 63.0 s INFO 13:40:34,242 VariantDataManager - QD: mean = 17.15 standard deviation = 4.73 INFO 13:40:34,457 VariantDataManager - MQRankSum: mean = 0.07 standard deviation = 0.57 INFO 13:40:34,665 VariantDataManager - ReadPosRankSum: mean = 0.55 standard deviation = 0.65 INFO 13:40:34,868 VariantDataManager - FS: mean = 1.74 standard deviation = 3.63 INFO 13:40:35,886 VariantDataManager - Annotations are now ordered by their information content: [QD, FS, ReadPosRankSum, MQRankSum] INFO 13:40:35,962 VariantDataManager - Training with 375325 variants after standard deviation thresholding. INFO 13:40:35,968 GaussianMixtureModel - Initializing model with 100 k-means iterations... INFO 13:40:40,429 ProgressMeter - GL000202.1:10465 6.85e+07 14.5 m 12.0 s 98.7% 14.7 m 11.0 s INFO 13:41:10,431 ProgressMeter - GL000202.1:10465 6.85e+07 15.0 m 13.0 s 98.7% 15.2 m 11.0 s INFO 13:41:33,749 VariantRecalibratorEngine - Finished iteration 0. INFO 13:41:40,432 ProgressMeter - GL000202.1:10465 6.85e+07 15.5 m 13.0 s 98.7% 15.7 m 12.0 s INFO 13:41:50,363 VariantRecalibratorEngine - Finished iteration 5. Current change in mixture coefficients = 0.39462 INFO 13:42:06,841 VariantRecalibratorEngine - Finished iteration 10. Current change in mixture coefficients = 0.18357 INFO 13:42:10,434 ProgressMeter - GL000202.1:10465 6.85e+07 16.0 m 14.0 s 98.7% 16.2 m 12.0 s INFO 13:42:23,554 VariantRecalibratorEngine - Finished iteration 15. Current change in mixture coefficients = 0.14579 INFO 13:42:40,435 ProgressMeter - GL000202.1:10465 6.85e+07 16.5 m 14.0 s 98.7% 16.7 m 13.0 s INFO 13:42:40,516 VariantRecalibratorEngine - Finished iteration 20. Current change in mixture coefficients = 0.07835 INFO 13:42:57,489 VariantRecalibratorEngine - Finished iteration 25. Current change in mixture coefficients = 0.05703 INFO 13:43:10,436 ProgressMeter - GL000202.1:10465 6.85e+07 17.0 m 14.0 s 98.7% 17.2 m 13.0 s INFO 13:43:14,449 VariantRecalibratorEngine - Finished iteration 30. Current change in mixture coefficients = 0.03713 INFO 13:43:31,403 VariantRecalibratorEngine - Finished iteration 35. Current change in mixture coefficients = 0.03699 INFO 13:43:40,438 ProgressMeter - GL000202.1:10465 6.85e+07 17.5 m 15.0 s 98.7% 17.7 m 13.0 s INFO 13:43:48,342 VariantRecalibratorEngine - Finished iteration 40. Current change in mixture coefficients = 0.02482 INFO 13:44:05,333 VariantRecalibratorEngine - Finished iteration 45. Current change in mixture coefficients = 0.01831 INFO 13:44:10,439 ProgressMeter - GL000202.1:10465 6.85e+07 18.0 m 15.0 s 98.7% 18.2 m 14.0 s INFO 13:44:22,870 VariantRecalibratorEngine - Finished iteration 50. Current change in mixture coefficients = 0.01870 INFO 13:44:39,883 VariantRecalibratorEngine - Finished iteration 55. Current change in mixture coefficients = 0.02007 INFO 13:44:40,441 ProgressMeter - GL000202.1:10465 6.85e+07 18.5 m 16.0 s 98.7% 18.7 m 14.0 s INFO 13:44:56,846 VariantRecalibratorEngine - Finished iteration 60. Current change in mixture coefficients = 0.01852 INFO 13:45:10,443 ProgressMeter - GL000202.1:10465 6.85e+07 19.0 m 16.0 s 98.7% 19.3 m 15.0 s INFO 13:45:13,823 VariantRecalibratorEngine - Finished iteration 65. Current change in mixture coefficients = 0.01471 INFO 13:45:30,818 VariantRecalibratorEngine - Finished iteration 70. Current change in mixture coefficients = 0.00995 INFO 13:45:40,444 ProgressMeter - GL000202.1:10465 6.85e+07 19.5 m 17.0 s 98.7% 19.8 m 15.0 s INFO 13:45:47,818 VariantRecalibratorEngine - Finished iteration 75. Current change in mixture coefficients = 0.00624 INFO 13:46:04,831 VariantRecalibratorEngine - Finished iteration 80. Current change in mixture coefficients = 0.00475 INFO 13:46:10,446 ProgressMeter - GL000202.1:10465 6.85e+07 20.0 m 17.0 s 98.7% 20.3 m 15.0 s INFO 13:46:22,644 VariantRecalibratorEngine - Finished iteration 85. Current change in mixture coefficients = 0.00374 INFO 13:46:39,652 VariantRecalibratorEngine - Finished iteration 90. Current change in mixture coefficients = 0.00300 INFO 13:46:40,447 ProgressMeter - GL000202.1:10465 6.85e+07 20.5 m 17.0 s 98.7% 20.8 m 16.0 s INFO 13:46:56,640 VariantRecalibratorEngine - Finished iteration 95. Current change in mixture coefficients = 0.00245 INFO 13:47:10,449 ProgressMeter - GL000202.1:10465 6.85e+07 21.0 m 18.0 s 98.7% 21.3 m 16.0 s INFO 13:47:13,607 VariantRecalibratorEngine - Finished iteration 100. Current change in mixture coefficients = 0.00204 INFO 13:47:16,993 VariantRecalibratorEngine - Convergence after 101 iterations! INFO 13:47:19,251 VariantRecalibratorEngine - Evaluating full set of 827861 variants... INFO 13:47:22,685 VariantDataManager - Training with worst 29004 scoring variants --> variants with LOD <= -5.0000. INFO 13:47:22,686 GaussianMixtureModel - Initializing model with 100 k-means iterations... INFO 13:47:23,139 VariantRecalibratorEngine - Finished iteration 0. INFO 13:47:23,321 VariantRecalibratorEngine - Finished iteration 5. Current change in mixture coefficients = 0.02809 INFO 13:47:23,500 VariantRecalibratorEngine - Finished iteration 10. Current change in mixture coefficients = 0.00699 INFO 13:47:23,537 VariantRecalibratorEngine - Convergence after 11 iterations! INFO 13:47:23,603 VariantRecalibratorEngine - Evaluating full set of 827861 variants... INFO 13:47:35,254 TrancheManager - Finding 16 tranches for 827861 variants INFO 13:47:35,933 TrancheManager - Tranche threshold 100.00 => selection metric threshold 0.000 INFO 13:47:36,044 TrancheManager - Found tranche for 100.000: 0.000 threshold starting with variant 0; running score is 0.000 INFO 13:47:36,045 TrancheManager - Tranche is Tranche ts=100.00 minVQSLod=-4113.5198 known=(576395 @ 2.6292) novel=(251466 @ 1.9145) truthSites(151701 accessible, 151701 called), name=anonymous] INFO 13:47:36,046 TrancheManager - Tranche threshold 99.90 => selection metric threshold 0.001 INFO 13:47:36,170 TrancheManager - Found tranche for 99.900: 0.001 threshold starting with variant 14087; running score is 0.001 INFO 13:47:36,170 TrancheManager - Tranche is Tranche ts=99.90 minVQSLod=-5.0036 known=(571615 @ 2.6541) novel=(242159 @ 2.0352) truthSites(151701 accessible, 151549 called), name=anonymous] INFO 13:47:36,171 TrancheManager - Tranche threshold 99.80 => selection metric threshold 0.002 INFO 13:47:36,277 TrancheManager - Found tranche for 99.800: 0.002 threshold starting with variant 32982; running score is 0.002 INFO 13:47:36,277 TrancheManager - Tranche is Tranche ts=99.80 minVQSLod=-1.8468 known=(564302 @ 2.6669) novel=(230577 @ 2.1046) truthSites(151701 accessible, 151397 called), name=anonymous] INFO 13:47:36,278 TrancheManager - Tranche threshold 99.70 => selection metric threshold 0.003 INFO 13:47:36,381 TrancheManager - Found tranche for 99.700: 0.003 threshold starting with variant 51939; running score is 0.003 INFO 13:47:36,382 TrancheManager - Tranche is Tranche ts=99.70 minVQSLod=-1.0255 known=(556200 @ 2.6726) novel=(219722 @ 2.1294) truthSites(151701 accessible, 151245 called), name=anonymous] INFO 13:47:36,382 TrancheManager - Tranche threshold 99.60 => selection metric threshold 0.004 INFO 13:47:36,485 TrancheManager - Found tranche for 99.600: 0.004 threshold starting with variant 75698; running score is 0.004 INFO 13:47:36,486 TrancheManager - Tranche is Tranche ts=99.60 minVQSLod=-0.5498 known=(545633 @ 2.6741) novel=(206530 @ 2.1363) truthSites(151701 accessible, 151094 called), name=anonymous] INFO 13:47:36,486 TrancheManager - Tranche threshold 99.50 => selection metric threshold 0.005 INFO 13:47:36,589 TrancheManager - Found tranche for 99.500: 0.005 threshold starting with variant 100907; running score is 0.005 INFO 13:47:36,590 TrancheManager - Tranche is Tranche ts=99.50 minVQSLod=-0.2389 known=(534248 @ 2.6738) novel=(192706 @ 2.1430) truthSites(151701 accessible, 150942 called), name=anonymous] INFO 13:47:36,591 TrancheManager - Tranche threshold 99.40 => selection metric threshold 0.006 INFO 13:47:36,692 TrancheManager - Found tranche for 99.400: 0.006 threshold starting with variant 128141; running score is 0.006 INFO 13:47:36,693 TrancheManager - Tranche is Tranche ts=99.40 minVQSLod=0.0010 known=(521578 @ 2.6722) novel=(178142 @ 2.1480) truthSites(151701 accessible, 150790 called), name=anonymous] INFO 13:47:36,693 TrancheManager - Tranche threshold 99.30 => selection metric threshold 0.007 INFO 13:47:36,795 TrancheManager - Found tranche for 99.300: 0.007 threshold starting with variant 149259; running score is 0.007 INFO 13:47:36,795 TrancheManager - Tranche is Tranche ts=99.30 minVQSLod=0.1494 known=(511506 @ 2.6739) novel=(167096 @ 2.1521) truthSites(151701 accessible, 150639 called), name=anonymous] INFO 13:47:36,796 TrancheManager - Tranche threshold 99.20 => selection metric threshold 0.008 INFO 13:47:36,897 TrancheManager - Found tranche for 99.200: 0.008 threshold starting with variant 171220; running score is 0.008 INFO 13:47:36,897 TrancheManager - Tranche is Tranche ts=99.20 minVQSLod=0.2851 known=(500812 @ 2.6719) novel=(155829 @ 2.1501) truthSites(151701 accessible, 150487 called), name=anonymous] INFO 13:47:36,898 TrancheManager - Tranche threshold 99.10 => selection metric threshold 0.009 INFO 13:47:36,998 TrancheManager - Found tranche for 99.100: 0.009 threshold starting with variant 192397; running score is 0.009 INFO 13:47:36,998 TrancheManager - Tranche is Tranche ts=99.10 minVQSLod=0.4042 known=(490277 @ 2.6707) novel=(145187 @ 2.1427) truthSites(151701 accessible, 150335 called), name=anonymous] INFO 13:47:36,999 TrancheManager - Tranche threshold 99.00 => selection metric threshold 0.010 INFO 13:47:37,098 TrancheManager - Found tranche for 99.000: 0.010 threshold starting with variant 212627; running score is 0.010 INFO 13:47:37,099 TrancheManager - Tranche is Tranche ts=99.00 minVQSLod=0.5097 known=(480018 @ 2.6675) novel=(135216 @ 2.1335) truthSites(151701 accessible, 150183 called), name=anonymous] INFO 13:47:37,099 TrancheManager - Tranche threshold 98.00 => selection metric threshold 0.020 INFO 13:47:37,197 TrancheManager - Found tranche for 98.000: 0.020 threshold starting with variant 299570; running score is 0.020 INFO 13:47:37,197 TrancheManager - Tranche is Tranche ts=98.00 minVQSLod=1.0245 known=(432040 @ 2.6627) novel=(96251 @ 2.0928) truthSites(151701 accessible, 148666 called), name=anonymous] INFO 13:47:37,198 TrancheManager - Tranche threshold 97.00 => selection metric threshold 0.030 INFO 13:47:37,294 TrancheManager - Found tranche for 97.000: 0.030 threshold starting with variant 335121; running score is 0.030 INFO 13:47:37,295 TrancheManager - Tranche is Tranche ts=97.00 minVQSLod=1.3014 known=(408549 @ 2.6653) novel=(84191 @ 2.0834) truthSites(151701 accessible, 147149 called), name=anonymous] INFO 13:47:37,295 TrancheManager - Tranche threshold 96.00 => selection metric threshold 0.040 INFO 13:47:37,391 TrancheManager - Found tranche for 96.000: 0.040 threshold starting with variant 359737; running score is 0.040 INFO 13:47:37,392 TrancheManager - Tranche is Tranche ts=96.00 minVQSLod=1.4838 known=(391099 @ 2.6653) novel=(77025 @ 2.0796) truthSites(151701 accessible, 145632 called), name=anonymous] INFO 13:47:37,392 TrancheManager - Tranche threshold 95.00 => selection metric threshold 0.050 INFO 13:47:37,488 TrancheManager - Found tranche for 95.000: 0.050 threshold starting with variant 379721; running score is 0.050 INFO 13:47:37,488 TrancheManager - Tranche is Tranche ts=95.00 minVQSLod=1.6263 known=(376225 @ 2.6655) novel=(71915 @ 2.0728) truthSites(151701 accessible, 144115 called), name=anonymous] INFO 13:47:37,489 TrancheManager - Tranche threshold 90.00 => selection metric threshold 0.100 INFO 13:47:37,583 TrancheManager - Found tranche for 90.000: 0.100 threshold starting with variant 440324; running score is 0.100 INFO 13:47:37,583 TrancheManager - Tranche is Tranche ts=90.00 minVQSLod=2.0515 known=(328474 @ 2.6646) novel=(59063 @ 2.0790) truthSites(151701 accessible, 136530 called), name=anonymous] INFO 13:47:37,591 VariantRecalibrator - Writing out recalibration table... INFO 13:47:40,450 ProgressMeter - GL000202.1:10465 6.85e+07 21.5 m 18.0 s 98.7% 21.8 m 17.0 s INFO 13:47:45,110 VariantRecalibrator - Writing out visualization Rscript file... INFO 13:47:45,216 VariantRecalibrator - Building QD x FS plot... INFO 13:47:45,222 VariantRecalibratorEngine - Evaluating full set of 3660 variants... INFO 13:47:45,693 VariantRecalibratorEngine - Evaluating full set of 3660 variants... INFO 13:47:45,954 VariantRecalibrator - Building QD x ReadPosRankSum plot... INFO 13:47:45,956 VariantRecalibratorEngine - Evaluating full set of 3660 variants... INFO 13:47:46,428 VariantRecalibratorEngine - Evaluating full set of 3660 variants... INFO 13:47:46,651 VariantRecalibrator - Building QD x MQRankSum plot... INFO 13:47:46,652 VariantRecalibratorEngine - Evaluating full set of 3660 variants... INFO 13:47:47,124 VariantRecalibratorEngine - Evaluating full set of 3660 variants... INFO 13:47:47,330 VariantRecalibrator - Building FS x ReadPosRankSum plot... INFO 13:47:47,331 VariantRecalibratorEngine - Evaluating full set of 3600 variants... INFO 13:47:47,794 VariantRecalibratorEngine - Evaluating full set of 3600 variants... INFO 13:47:47,995 VariantRecalibrator - Building FS x MQRankSum plot... INFO 13:47:47,996 VariantRecalibratorEngine - Evaluating full set of 3600 variants... INFO 13:47:48,457 VariantRecalibratorEngine - Evaluating full set of 3600 variants... INFO 13:47:48,657 VariantRecalibrator - Building ReadPosRankSum x MQRankSum plot... INFO 13:47:48,658 VariantRecalibratorEngine - Evaluating full set of 3600 variants... INFO 13:47:49,123 VariantRecalibratorEngine - Evaluating full set of 3600 variants... INFO 13:47:49,336 VariantRecalibrator - Executing: Rscript /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1.to.22.Partial.HC.SNV.R INFO 13:48:05,469 VariantRecalibrator - Executing: Rscript (resource)org/broadinstitute/sting/gatk/walkers/variantrecalibration/plot_Tranches.R /isilon/sequencing/Kurt/VALIDATE_HC_SENSITIVITY/Mendel.1.to.22.Partial.HC.SNV.tranches 2.15 INFO 13:48:10,452 ProgressMeter - GL000202.1:10465 6.85e+07 22.0 m 19.0 s 98.7% 22.3 m 17.0 s INFO 13:48:14,361 ProgressMeter - done 6.85e+07 22.1 m 19.0 s 98.7% 22.4 m 17.0 s INFO 13:48:14,361 ProgressMeter - Total runtime 1324.11 secs, 22.07 min, 0.37 hours INFO 13:48:17,862 GATKRunReport - Uploaded run statistics report to AWS S3