.command.out - Workdir - DAQ:CONTROL_VARIANT_CALLING:CONTROL_GERMLINE_VC:BAM_VARIANT_CALLING_SENTIEON_HAPLOTYPER_RF:DV_RESCUE (germline_control_2;germline_rescue_targets)

File Info

Filename: .command.out
Full Path: s3://natera-rnd-pltf-dev-nextflow-scratch-01/work/ad/b33ce4291edd44e519e78f21b01746/.command.out
Size: 13.2 KB
Task: DAQ:CONTROL_VARIANT_CALLING:CONTROL_GERMLINE_VC:BAM_VARIANT_CALLING_SENTIEON_HAPLOTYPER_RF:DV_RESCUE (germline_control_2;germline_rescue_targets)
Attempt
Content

***** Intermediate results will be written to tmp in docker. ****


***** Running the command:*****
time seq 0 3 | parallel -q --halt 2 --line-buffer /opt/deepvariant/bin/make_examples --mode calling --ref "Homo_sapiens_assembly38.fasta" --reads "Sig_18_Blood.recalibrated.bam" --examples "tmp/make_examples.tfrecord@4.gz" --channels "insert_size" --gvcf "tmp/gvcf.tfrecord@4.gz" --regions "germline_rescue_targets.bed" --task {}

I0603 20:59:04.315143 139989790717760 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.316437 139984589920064 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.371931 140644145157952 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.378626 140644145157952 make_examples_core.py:301] Task 1/4: Preparing inputs
I0603 20:59:04.387577 140644145157952 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.323181 139989790717760 make_examples_core.py:301] Task 0/4: Preparing inputs
I0603 20:59:04.331938 139989790717760 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.323720 139984589920064 make_examples_core.py:301] Task 2/4: Preparing inputs
I0603 20:59:04.332611 139984589920064 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.345618 140146715572032 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.352373 140146715572032 make_examples_core.py:301] Task 3/4: Preparing inputs
I0603 20:59:04.361412 140146715572032 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:04.655338 140644145157952 make_examples_core.py:301] Task 1/4: Common contigs are ['chr1', 'chr2', 'chr3', 'chr4', 'chr5', 'chr6', 'chr7', 'chr8', 'chr9', 'chr10', 'chr11', 'chr12', 'chr13', 'chr14', 'chr15', 'chr16', 'chr17', 'chr18', 'chr19', 'chr20', 'chr21', 'chr22', 'chrX', 'chrY', 'chrM']
I0603 20:59:04.597006 139989790717760 make_examples_core.py:301] Task 0/4: Common contigs are ['chr1', 'chr2', 'chr3', 'chr4', 'chr5', 'chr6', 'chr7', 'chr8', 'chr9', 'chr10', 'chr11', 'chr12', 'chr13', 'chr14', 'chr15', 'chr16', 'chr17', 'chr18', 'chr19', 'chr20', 'chr21', 'chr22', 'chrX', 'chrY', 'chrM']
I0603 20:59:04.599720 139984589920064 make_examples_core.py:301] Task 2/4: Common contigs are ['chr1', 'chr2', 'chr3', 'chr4', 'chr5', 'chr6', 'chr7', 'chr8', 'chr9', 'chr10', 'chr11', 'chr12', 'chr13', 'chr14', 'chr15', 'chr16', 'chr17', 'chr18', 'chr19', 'chr20', 'chr21', 'chr22', 'chrX', 'chrY', 'chrM']
I0603 20:59:04.631592 140146715572032 make_examples_core.py:301] Task 3/4: Common contigs are ['chr1', 'chr2', 'chr3', 'chr4', 'chr5', 'chr6', 'chr7', 'chr8', 'chr9', 'chr10', 'chr11', 'chr12', 'chr13', 'chr14', 'chr15', 'chr16', 'chr17', 'chr18', 'chr19', 'chr20', 'chr21', 'chr22', 'chrX', 'chrY', 'chrM']
I0603 20:59:04.829287 139989790717760 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0603 20:59:04.830933 139984589920064 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0603 20:59:04.914700 140644145157952 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0603 20:59:05.099447 139989790717760 make_examples_core.py:301] Task 0/4: Starting from v0.9.0, --use_ref_for_cram is default to true. If you are using CRAM input, note that we will decode CRAM using the reference you passed in with --ref
I0603 20:59:05.096364 139984589920064 make_examples_core.py:301] Task 2/4: Starting from v0.9.0, --use_ref_for_cram is default to true. If you are using CRAM input, note that we will decode CRAM using the reference you passed in with --ref
I0603 20:59:04.899753 140146715572032 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0603 20:59:05.184804 140644145157952 make_examples_core.py:301] Task 1/4: Starting from v0.9.0, --use_ref_for_cram is default to true. If you are using CRAM input, note that we will decode CRAM using the reference you passed in with --ref
I0603 20:59:05.221837 140644145157952 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.265297 140644145157952 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.266010 140644145157952 make_examples_core.py:301] Task 1/4: Writing gvcf records to tmp/gvcf.tfrecord-00001-of-00004.gz
I0603 20:59:05.266479 140644145157952 make_examples_core.py:301] Task 1/4: Writing examples to tmp/make_examples.tfrecord-00001-of-00004.gz
I0603 20:59:05.266554 140644145157952 make_examples_core.py:301] Task 1/4: Overhead for preparing inputs: 0 seconds
I0603 20:59:05.268869 140644145157952 make_examples_core.py:301] Task 1/4: 0 candidates (0 examples) [0.00s elapsed]
I0603 20:59:05.138923 139989790717760 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.182677 139989790717760 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.183434 139989790717760 make_examples_core.py:301] Task 0/4: Writing gvcf records to tmp/gvcf.tfrecord-00000-of-00004.gz
I0603 20:59:05.183960 139989790717760 make_examples_core.py:301] Task 0/4: Writing examples to tmp/make_examples.tfrecord-00000-of-00004.gz
I0603 20:59:05.184030 139989790717760 make_examples_core.py:301] Task 0/4: Overhead for preparing inputs: 0 seconds
I0603 20:59:05.187001 139989790717760 make_examples_core.py:301] Task 0/4: 0 candidates (0 examples) [0.00s elapsed]
I0603 20:59:05.131160 139984589920064 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.175016 139984589920064 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.175739 139984589920064 make_examples_core.py:301] Task 2/4: Writing gvcf records to tmp/gvcf.tfrecord-00002-of-00004.gz
I0603 20:59:05.176210 139984589920064 make_examples_core.py:301] Task 2/4: Writing examples to tmp/make_examples.tfrecord-00002-of-00004.gz
I0603 20:59:05.176279 139984589920064 make_examples_core.py:301] Task 2/4: Overhead for preparing inputs: 0 seconds
I0603 20:59:05.178764 139984589920064 make_examples_core.py:301] Task 2/4: 0 candidates (0 examples) [0.00s elapsed]
I0603 20:59:05.170858 140146715572032 make_examples_core.py:301] Task 3/4: Starting from v0.9.0, --use_ref_for_cram is default to true. If you are using CRAM input, note that we will decode CRAM using the reference you passed in with --ref
I0603 20:59:05.204957 140146715572032 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.250789 140146715572032 genomics_reader.py:222] Reading Sig_18_Blood.recalibrated.bam with NativeSamReader
I0603 20:59:05.251745 140146715572032 make_examples_core.py:301] Task 3/4: Writing gvcf records to tmp/gvcf.tfrecord-00003-of-00004.gz
I0603 20:59:05.252338 140146715572032 make_examples_core.py:301] Task 3/4: Writing examples to tmp/make_examples.tfrecord-00003-of-00004.gz
I0603 20:59:05.252427 140146715572032 make_examples_core.py:301] Task 3/4: Overhead for preparing inputs: 0 seconds
I0603 20:59:05.254847 140146715572032 make_examples_core.py:301] Task 3/4: 0 candidates (0 examples) [0.00s elapsed]
I0603 20:59:06.718316 140644145157952 make_examples_core.py:301] Task 1/4: Writing example info to tmp/make_examples.tfrecord-00001-of-00004.gz.example_info.json
I0603 20:59:06.718673 140644145157952 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0603 20:59:06.719325 140644145157952 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0603 20:59:06.720042 140644145157952 make_examples_core.py:301] Task 1/4: Found 2 candidate variants
I0603 20:59:06.720085 140644145157952 make_examples_core.py:301] Task 1/4: Created 2 examples
I0603 20:59:06.848544 140146715572032 make_examples_core.py:301] Task 3/4: Writing example info to tmp/make_examples.tfrecord-00003-of-00004.gz.example_info.json
I0603 20:59:06.848958 140146715572032 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0603 20:59:06.849830 140146715572032 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0603 20:59:06.850613 140146715572032 make_examples_core.py:301] Task 3/4: Found 4 candidate variants
I0603 20:59:06.850668 140146715572032 make_examples_core.py:301] Task 3/4: Created 4 examples
I0603 20:59:07.158800 139984589920064 make_examples_core.py:301] Task 2/4: Writing example info to tmp/make_examples.tfrecord-00002-of-00004.gz.example_info.json
I0603 20:59:07.159151 139984589920064 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0603 20:59:07.159702 139984589920064 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0603 20:59:07.160536 139984589920064 make_examples_core.py:301] Task 2/4: Found 4 candidate variants
I0603 20:59:07.160597 139984589920064 make_examples_core.py:301] Task 2/4: Created 4 examples
I0603 20:59:07.268282 139989790717760 make_examples_core.py:301] Task 0/4: Writing example info to tmp/make_examples.tfrecord-00000-of-00004.gz.example_info.json
I0603 20:59:07.268650 139989790717760 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0603 20:59:07.269279 139989790717760 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0603 20:59:07.269993 139989790717760 make_examples_core.py:301] Task 0/4: Found 4 candidate variants
I0603 20:59:07.270045 139989790717760 make_examples_core.py:301] Task 0/4: Created 9 examples

real	0m5.197s
user	0m19.900s
sys	0m19.551s

***** Running the command:*****
time /opt/deepvariant/bin/call_variants --outfile "tmp/call_variants_output.tfrecord.gz" --examples "tmp/make_examples.tfrecord@4.gz" --checkpoint "/opt/models/wes"

/usr/local/lib/python3.8/dist-packages/tensorflow_addons/utils/tfa_eol_msg.py:23: UserWarning: 

TensorFlow Addons (TFA) has ended development and introduction of new features.
TFA has entered a minimal maintenance and release mode until a planned end of life in May 2024.
Please modify downstream libraries to take dependencies from other repositories in our TensorFlow community (e.g. Keras, Keras-CV, and Keras-NLP). 

For more information see: https://github.com/tensorflow/addons/issues/2807 

  warnings.warn(
I0603 20:59:09.448223 140659684386624 call_variants.py:563] Total 1 writing processes started.
I0603 20:59:09.449623 140659684386624 dv_utils.py:370] From tmp/make_examples.tfrecord-00000-of-00004.gz.example_info.json: Shape of input examples: [100, 221, 7], Channels of input examples: [1, 2, 3, 4, 5, 6, 19].
I0603 20:59:09.449689 140659684386624 call_variants.py:588] Shape of input examples: [100, 221, 7]
I0603 20:59:09.449917 140659684386624 call_variants.py:592] Use saved model: True
I0603 20:59:13.332532 140659684386624 dv_utils.py:370] From /opt/models/wes/example_info.json: Shape of input examples: [100, 221, 7], Channels of input examples: [1, 2, 3, 4, 5, 6, 19].
I0603 20:59:13.332693 140659684386624 dv_utils.py:370] From tmp/make_examples.tfrecord-00000-of-00004.gz.example_info.json: Shape of input examples: [100, 221, 7], Channels of input examples: [1, 2, 3, 4, 5, 6, 19].
I0603 20:59:13.932124 140659684386624 call_variants.py:716] Predicted 19 examples in 1 batches [2.576 sec per 100].
I0603 20:59:14.002590 140659684386624 call_variants.py:779] Complete: call_variants.

real	0m7.058s
user	0m11.194s
sys	0m11.573s

***** Running the command:*****
time /opt/deepvariant/bin/postprocess_variants --ref "Homo_sapiens_assembly38.fasta" --infile "tmp/call_variants_output.tfrecord.gz" --outfile "germline_control_2.dv_rescue.vcf.gz" --cpus "4" --gvcf_outfile "germline_control_2.dv_rescue.g.vcf.gz" --nonvariant_site_tfrecord_path "tmp/gvcf.tfrecord@4.gz"

I0603 20:59:16.360241 139650774751040 postprocess_variants.py:1211] Using sample name from call_variants output. Sample name: Sig_18_Blood
2026-06-03 20:59:16.364200: I deepvariant/postprocess_variants.cc:94] Read from: tmp/call_variants_output-00000-of-00001.tfrecord.gz
2026-06-03 20:59:16.364352: I deepvariant/postprocess_variants.cc:109] Total #entries in single_site_calls = 19
I0603 20:59:16.365362 139650774751040 postprocess_variants.py:1313] CVO sorting took 7.847150166829427e-05 minutes
I0603 20:59:16.365504 139650774751040 postprocess_variants.py:1316] Transforming call_variants_output to variants.
I0603 20:59:16.365533 139650774751040 postprocess_variants.py:1318] Using 4 CPUs for parallelization of variant transformation.
I0603 20:59:16.384595 139650774751040 postprocess_variants.py:1211] Using sample name from call_variants output. Sample name: Sig_18_Blood
I0603 20:59:16.389527 139650774751040 postprocess_variants.py:1386] Processing variants (and writing to temporary file) took 3.998279571533203e-05 minutes
I0603 20:59:16.479736 139650774751040 postprocess_variants.py:1407] Finished writing VCF and gVCF in 0.0014991839726765952 minutes.

real	0m2.035s
user	0m5.012s
sys	0m9.609s

***** Running the command:*****
time /opt/deepvariant/bin/vcf_stats_report --input_vcf "germline_control_2.dv_rescue.vcf.gz" --outfile_base "germline_control_2.dv_rescue"

I0603 20:59:18.393203 139915185895232 genomics_reader.py:222] Reading germline_control_2.dv_rescue.vcf.gz with NativeVcfReader

real	0m1.963s
user	0m4.843s
sys	0m9.577s