[bwa_index] Pack FASTA... 0.40 sec [bwa_index] Construct BWT for the packed sequence... [BWTIncCreate] textLength=156154496, availableWord=22987304 [BWTIncConstructFromPacked] 10 iterations done. 37918224 characters processed. [BWTIncConstructFromPacked] 20 iterations done. 70049888 characters processed. [BWTIncConstructFromPacked] 30 iterations done. 98604576 characters processed. [BWTIncConstructFromPacked] 40 iterations done. 123980016 characters processed. [BWTIncConstructFromPacked] 50 iterations done. 146529744 characters processed. [bwt_gen] Finished constructing BWT in 55 iterations. [bwa_index] 31.30 seconds elapse. [bwa_index] Update BWT... 0.27 sec [bwa_index] Pack forward-only FASTA... 0.25 sec [bwa_index] Construct SA from BWT and Occ... 15.68 sec [main] Version: 0.7.17-r1188 [main] CMD: bwa index ref/chr18.fa [main] Real time: 49.434 sec; CPU: 47.904 sec [M::bwa_idx_load_from_disk] read 0 ALT contigs [M::process] read 246561 sequences (37230711 bp)... [M::mem_process_seqs] Processed 246561 reads in 31.684 CPU sec, 7.922 real sec [main] Version: 0.7.17-r1188 [main] CMD: bwa mem -t 4 -R @RG\tID:1\tSM:CHM1_CHM13_3\tLB:Pond-482886 ref/chr18.fa reads/r1.fq [main] Real time: 8.612 sec; CPU: 31.928 sec normalize v0.5 options: input VCF file - [o] output VCF file - [w] sorting window size 10000 [n] no fail on reference inconsistency for non SNPs false [q] quiet false [d] debug false [r] reference FASTA file ref/chr18.fa stats: biallelic no. left trimmed : 55 no. right trimmed : 375 no. left and right trimmed : 46 no. right trimmed and left aligned : 0 no. left aligned : 0 total no. biallelic normalized : 476 multiallelic no. left trimmed : 4 no. right trimmed : 16 no. left and right trimmed : 12 no. right trimmed and left aligned : 0 no. left aligned : 0 total no. multiallelic normalized : 32 total no. variants normalized : 508 total no. variants observed : 2402 total no. reference observed : 0 Time elapsed: 0.05s INFO 2018-11-07 15:49:14 CreateSequenceDictionary ********** NOTE: Picard's command line syntax is changing. ********** ********** For more information, please see: ********** https://github.com/broadinstitute/picard/wiki/Command-Line-Syntax-Transition-For-Users-(Pre-Transition) ********** ********** The command line looks like this in the new syntax: ********** ********** CreateSequenceDictionary -REFERENCE ref/chr18.fa -OUTPUT ref/chr18.dict ********** 15:49:14.695 INFO NativeLibraryLoader - Loading libgkl_compression.so from jar:file:/home/www/miniconda3/envs/engine/share/picard-2.18.14-0/picard.jar!/com/intel/gkl/native/libgkl_compression.so [Wed Nov 07 15:49:14 UTC 2018] CreateSequenceDictionary OUTPUT=ref/chr18.dict REFERENCE=ref/chr18.fa TRUNCATE_NAMES_AT_WHITESPACE=true NUM_SEQUENCES=2147483647 VERBOSITY=INFO QUIET=false VALIDATION_STRINGENCY=STRICT COMPRESSION_LEVEL=5 MAX_RECORDS_IN_RAM=500000 CREATE_INDEX=false CREATE_MD5_FILE=false GA4GH_CLIENT_SECRETS=client_secrets.json USE_JDK_DEFLATER=false USE_JDK_INFLATER=false [Wed Nov 07 15:49:14 UTC 2018] Executing as www@recipes on Linux 4.10.0-42-generic amd64; OpenJDK 64-Bit Server VM 1.8.0_152-release-1056-b12; Deflater: Intel; Inflater: Intel; Provider GCS is not available; Picard version: 2.18.14-SNAPSHOT [Wed Nov 07 15:49:15 UTC 2018] picard.sam.CreateSequenceDictionary done. Elapsed time: 0.01 minutes. Runtime.totalMemory()=514850816 15:49:16.326 INFO NativeLibraryLoader - Loading libgkl_compression.so from jar:file:/home/www/src/gatk-4.0.11.0/gatk-package-4.0.11.0-local.jar!/com/intel/gkl/native/libgkl_compression.so 15:49:17.957 INFO HaplotypeCaller - ------------------------------------------------------------ 15:49:17.957 INFO HaplotypeCaller - The Genome Analysis Toolkit (GATK) v4.0.11.0 15:49:17.958 INFO HaplotypeCaller - For support and documentation go to https://software.broadinstitute.org/gatk/ 15:49:17.958 INFO HaplotypeCaller - Executing as www@recipes on Linux v4.10.0-42-generic amd64 15:49:17.958 INFO HaplotypeCaller - Java runtime: OpenJDK 64-Bit Server VM v1.8.0_152-release-1056-b12 15:49:17.958 INFO HaplotypeCaller - Start Date/Time: November 7, 2018 3:49:16 PM UTC 15:49:17.958 INFO HaplotypeCaller - ------------------------------------------------------------ 15:49:17.958 INFO HaplotypeCaller - ------------------------------------------------------------ 15:49:17.959 INFO HaplotypeCaller - HTSJDK Version: 2.16.1 15:49:17.959 INFO HaplotypeCaller - Picard Version: 2.18.13 15:49:17.959 INFO HaplotypeCaller - HTSJDK Defaults.COMPRESSION_LEVEL : 2 15:49:17.959 INFO HaplotypeCaller - HTSJDK Defaults.USE_ASYNC_IO_READ_FOR_SAMTOOLS : false 15:49:17.959 INFO HaplotypeCaller - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_SAMTOOLS : true 15:49:17.959 INFO HaplotypeCaller - HTSJDK Defaults.USE_ASYNC_IO_WRITE_FOR_TRIBBLE : false 15:49:17.959 INFO HaplotypeCaller - Deflater: IntelDeflater 15:49:17.959 INFO HaplotypeCaller - Inflater: IntelInflater 15:49:17.959 INFO HaplotypeCaller - GCS max retries/reopens: 20 15:49:17.959 INFO HaplotypeCaller - Requester pays: disabled 15:49:17.959 INFO HaplotypeCaller - Initializing engine 15:49:18.158 INFO HaplotypeCaller - Done initializing engine 15:49:18.161 INFO HaplotypeCallerEngine - Disabling physical phasing, which is supported only for reference-model confidence output 15:49:18.168 INFO NativeLibraryLoader - Loading libgkl_utils.so from jar:file:/home/www/src/gatk-4.0.11.0/gatk-package-4.0.11.0-local.jar!/com/intel/gkl/native/libgkl_utils.so 15:49:18.200 INFO NativeLibraryLoader - Loading libgkl_pairhmm_omp.so from jar:file:/home/www/src/gatk-4.0.11.0/gatk-package-4.0.11.0-local.jar!/com/intel/gkl/native/libgkl_pairhmm_omp.so 15:49:18.232 WARN IntelPairHmm - Flush-to-zero (FTZ) is enabled when running PairHMM 15:49:18.233 INFO IntelPairHmm - Available threads: 8 15:49:18.233 INFO IntelPairHmm - Requested threads: 4 15:49:18.233 INFO PairHMM - Using the OpenMP multi-threaded AVX-accelerated native PairHMM implementation 15:49:18.247 INFO ProgressMeter - Starting traversal 15:49:18.248 INFO ProgressMeter - Current Locus Elapsed Minutes Regions Processed Regions/Minute 15:50:53.029 INFO ProgressMeter - chr18:109182 1.6 630 398.8 15:51:25.639 INFO ProgressMeter - chr18:111480 2.1 640 301.4 15:51:35.657 INFO ProgressMeter - chr18:335032 2.3 1740 759.8 15:51:45.731 INFO ProgressMeter - chr18:832577 2.5 4580 1863.3 15:51:55.731 INFO ProgressMeter - chr18:55678210 2.6 187810 71554.4 15:51:58.390 INFO HaplotypeCaller - 7602 read(s) filtered by: ((((((((MappingQualityReadFilter AND MappingQualityAvailableReadFilter) AND MappedReadFilter) AND NotSecondaryAlignmentReadFilter) AND NotDuplicateReadFilter) AND PassesVendorQualityCheckReadFilter) AND NonZeroReferenceLengthAlignmentReadFilter) AND GoodCigarReadFilter) AND WellformedReadFilter) 7602 read(s) filtered by: (((((((MappingQualityReadFilter AND MappingQualityAvailableReadFilter) AND MappedReadFilter) AND NotSecondaryAlignmentReadFilter) AND NotDuplicateReadFilter) AND PassesVendorQualityCheckReadFilter) AND NonZeroReferenceLengthAlignmentReadFilter) AND GoodCigarReadFilter) 7602 read(s) filtered by: ((((((MappingQualityReadFilter AND MappingQualityAvailableReadFilter) AND MappedReadFilter) AND NotSecondaryAlignmentReadFilter) AND NotDuplicateReadFilter) AND PassesVendorQualityCheckReadFilter) AND NonZeroReferenceLengthAlignmentReadFilter) 7602 read(s) filtered by: (((((MappingQualityReadFilter AND MappingQualityAvailableReadFilter) AND MappedReadFilter) AND NotSecondaryAlignmentReadFilter) AND NotDuplicateReadFilter) AND PassesVendorQualityCheckReadFilter) 7602 read(s) filtered by: ((((MappingQualityReadFilter AND MappingQualityAvailableReadFilter) AND MappedReadFilter) AND NotSecondaryAlignmentReadFilter) AND NotDuplicateReadFilter) 7602 read(s) filtered by: (((MappingQualityReadFilter AND MappingQualityAvailableReadFilter) AND MappedReadFilter) AND NotSecondaryAlignmentReadFilter) 7602 read(s) filtered by: ((MappingQualityReadFilter AND MappingQualityAvailableReadFilter) AND MappedReadFilter) 7602 read(s) filtered by: (MappingQualityReadFilter AND MappingQualityAvailableReadFilter) 7602 read(s) filtered by: MappingQualityReadFilter 15:51:58.390 INFO ProgressMeter - chr18:78074941 2.7 262477 98341.6 15:51:58.392 INFO ProgressMeter - Traversal complete. Processed 262477 total regions in 2.7 minutes. 15:51:58.395 INFO VectorLoglessPairHMM - Time spent in setup for JNI call : 0.18056571500000002 15:51:58.396 INFO PairHMM - Total compute time in PairHMM computeLogLikelihoods() : 89.902569235 15:51:58.396 INFO SmithWatermanAligner - Total compute time in java Smith-Waterman : 13.88 sec 15:51:58.397 INFO HaplotypeCaller - Shutting down engine [November 7, 2018 3:51:58 PM UTC] org.broadinstitute.hellbender.tools.walkers.haplotypecaller.HaplotypeCaller done. Elapsed time: 2.70 minutes. Runtime.totalMemory()=5481431040 Using GATK jar /home/www/src/gatk-4.0.11.0/gatk-package-4.0.11.0-local.jar Running: java -Dsamjdk.use_async_io_read_samtools=false -Dsamjdk.use_async_io_write_samtools=true -Dsamjdk.use_async_io_write_tribble=false -Dsamjdk.compression_level=2 -jar /home/www/src/gatk-4.0.11.0/gatk-package-4.0.11.0-local.jar HaplotypeCaller -R ref/chr18.fa -I align18.bam -O align18.bam.gatk.vcf