***** 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 "HCC1395_BL.recalibrated.bam" --examples "tmp/make_examples.tfrecord@4.gz" --channels "insert_size" --gvcf "tmp/gvcf.tfrecord@4.gz" --regions "germline_rescue_targets.bed" --task {}

I0605 03:29:29.676646 140551390205760 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.689946 140551390205760 make_examples_core.py:301] Task 2/4: Preparing inputs
I0605 03:29:29.699271 140551390205760 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.704357 140448066774848 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.737573 140400363181888 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.749077 140400363181888 make_examples_core.py:301] Task 0/4: Preparing inputs
I0605 03:29:29.758484 140400363181888 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.716055 140448066774848 make_examples_core.py:301] Task 1/4: Preparing inputs
I0605 03:29:29.725336 140448066774848 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.756865 140473277118272 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.768598 140473277118272 make_examples_core.py:301] Task 3/4: Preparing inputs
I0605 03:29:29.777832 140473277118272 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:29.964104 140551390205760 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']
I0605 03:29:30.031885 140400363181888 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']
I0605 03:29:29.992779 140448066774848 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']
I0605 03:29:30.044746 140473277118272 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']
I0605 03:29:30.127230 140551390205760 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0605 03:29:30.219057 140400363181888 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0605 03:29:30.164438 140448066774848 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0605 03:29:30.237246 140473277118272 genomics_reader.py:222] Reading germline_rescue_targets.bed with NativeBedReader
I0605 03:29:30.372343 140551390205760 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
I0605 03:29:30.417695 140551390205760 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.460897 140551390205760 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.461476 140551390205760 make_examples_core.py:301] Task 2/4: Writing gvcf records to tmp/gvcf.tfrecord-00002-of-00004.gz
I0605 03:29:30.461901 140551390205760 make_examples_core.py:301] Task 2/4: Writing examples to tmp/make_examples.tfrecord-00002-of-00004.gz
I0605 03:29:30.461948 140551390205760 make_examples_core.py:301] Task 2/4: Overhead for preparing inputs: 0 seconds
I0605 03:29:30.464298 140551390205760 make_examples_core.py:301] Task 2/4: 0 candidates (0 examples) [0.00s elapsed]
I0605 03:29:30.455031 140400363181888 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
I0605 03:29:30.493873 140400363181888 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.407034 140448066774848 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
I0605 03:29:30.449965 140448066774848 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.493333 140448066774848 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.493894 140448066774848 make_examples_core.py:301] Task 1/4: Writing gvcf records to tmp/gvcf.tfrecord-00001-of-00004.gz
I0605 03:29:30.494385 140448066774848 make_examples_core.py:301] Task 1/4: Writing examples to tmp/make_examples.tfrecord-00001-of-00004.gz
I0605 03:29:30.494438 140448066774848 make_examples_core.py:301] Task 1/4: Overhead for preparing inputs: 0 seconds
I0605 03:29:30.496578 140448066774848 make_examples_core.py:301] Task 1/4: 0 candidates (0 examples) [0.00s elapsed]
I0605 03:29:30.478779 140473277118272 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
I0605 03:29:30.537748 140400363181888 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.538447 140400363181888 make_examples_core.py:301] Task 0/4: Writing gvcf records to tmp/gvcf.tfrecord-00000-of-00004.gz
I0605 03:29:30.539001 140400363181888 make_examples_core.py:301] Task 0/4: Writing examples to tmp/make_examples.tfrecord-00000-of-00004.gz
I0605 03:29:30.539076 140400363181888 make_examples_core.py:301] Task 0/4: Overhead for preparing inputs: 0 seconds
I0605 03:29:30.542088 140400363181888 make_examples_core.py:301] Task 0/4: 0 candidates (0 examples) [0.00s elapsed]
I0605 03:29:30.524615 140473277118272 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.568340 140473277118272 genomics_reader.py:222] Reading HCC1395_BL.recalibrated.bam with NativeSamReader
I0605 03:29:30.568985 140473277118272 make_examples_core.py:301] Task 3/4: Writing gvcf records to tmp/gvcf.tfrecord-00003-of-00004.gz
I0605 03:29:30.569453 140473277118272 make_examples_core.py:301] Task 3/4: Writing examples to tmp/make_examples.tfrecord-00003-of-00004.gz
I0605 03:29:30.569520 140473277118272 make_examples_core.py:301] Task 3/4: Overhead for preparing inputs: 0 seconds
I0605 03:29:30.571780 140473277118272 make_examples_core.py:301] Task 3/4: 0 candidates (0 examples) [0.00s elapsed]
I0605 03:29:32.015956 140448066774848 make_examples_core.py:301] Task 1/4: Writing example info to tmp/make_examples.tfrecord-00001-of-00004.gz.example_info.json
I0605 03:29:32.016131 140448066774848 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0605 03:29:32.016553 140448066774848 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0605 03:29:32.016946 140448066774848 make_examples_core.py:301] Task 1/4: Found 1 candidate variants
I0605 03:29:32.016980 140448066774848 make_examples_core.py:301] Task 1/4: Created 1 examples
I0605 03:29:32.131791 140473277118272 make_examples_core.py:301] Task 3/4: Writing example info to tmp/make_examples.tfrecord-00003-of-00004.gz.example_info.json
I0605 03:29:32.132140 140473277118272 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0605 03:29:32.132660 140473277118272 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0605 03:29:32.133322 140473277118272 make_examples_core.py:301] Task 3/4: Found 4 candidate variants
I0605 03:29:32.133374 140473277118272 make_examples_core.py:301] Task 3/4: Created 4 examples
I0605 03:29:32.391245 140551390205760 make_examples_core.py:301] Task 2/4: Writing example info to tmp/make_examples.tfrecord-00002-of-00004.gz.example_info.json
I0605 03:29:32.391427 140551390205760 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0605 03:29:32.391824 140551390205760 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0605 03:29:32.392214 140551390205760 make_examples_core.py:301] Task 2/4: Found 6 candidate variants
I0605 03:29:32.392243 140551390205760 make_examples_core.py:301] Task 2/4: Created 6 examples
I0605 03:29:33.384783 140400363181888 make_examples_core.py:301] Task 0/4: Writing example info to tmp/make_examples.tfrecord-00000-of-00004.gz.example_info.json
I0605 03:29:33.384981 140400363181888 make_examples_core.py:2958] example_shape = [100, 221, 7]
I0605 03:29:33.385421 140400363181888 make_examples_core.py:2959] example_channels = [1, 2, 3, 4, 5, 6, 19]
I0605 03:29:33.385879 140400363181888 make_examples_core.py:301] Task 0/4: Found 4 candidate variants
I0605 03:29:33.385912 140400363181888 make_examples_core.py:301] Task 0/4: Created 9 examples

real	0m5.923s
user	0m30.148s
sys	0m39.737s

***** 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(
I0605 03:29:35.569560 140184461141824 call_variants.py:563] Total 1 writing processes started.
I0605 03:29:35.571026 140184461141824 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].
I0605 03:29:35.571086 140184461141824 call_variants.py:588] Shape of input examples: [100, 221, 7]
I0605 03:29:35.571315 140184461141824 call_variants.py:592] Use saved model: True
I0605 03:29:39.871600 140184461141824 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].
I0605 03:29:39.871821 140184461141824 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].
I0605 03:29:40.720933 140184461141824 call_variants.py:716] Predicted 20 examples in 1 batches [3.571 sec per 100].
I0605 03:29:40.855780 140184461141824 call_variants.py:779] Complete: call_variants.

real	0m8.130s
user	0m9.667s
sys	0m21.057s

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

I0605 03:29:43.584893 140321230882624 postprocess_variants.py:1211] Using sample name from call_variants output. Sample name: HCC1395_BL
2026-06-05 03:29:43.588690: I deepvariant/postprocess_variants.cc:94] Read from: tmp/call_variants_output-00000-of-00001.tfrecord.gz
2026-06-05 03:29:43.588852: I deepvariant/postprocess_variants.cc:109] Total #entries in single_site_calls = 20
I0605 03:29:43.589855 140321230882624 postprocess_variants.py:1313] CVO sorting took 7.577737172444661e-05 minutes
I0605 03:29:43.590041 140321230882624 postprocess_variants.py:1316] Transforming call_variants_output to variants.
I0605 03:29:43.590071 140321230882624 postprocess_variants.py:1318] Using 4 CPUs for parallelization of variant transformation.
I0605 03:29:43.612558 140321230882624 postprocess_variants.py:1211] Using sample name from call_variants output. Sample name: HCC1395_BL
I0605 03:29:43.618606 140321230882624 postprocess_variants.py:1386] Processing variants (and writing to temporary file) took 5.810658137003581e-05 minutes
I0605 03:29:43.709915 140321230882624 postprocess_variants.py:1407] Finished writing VCF and gVCF in 0.0015195409456888835 minutes.

real	0m2.105s
user	0m4.968s
sys	0m9.720s

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

I0605 03:29:45.672483 140116181272384 genomics_reader.py:222] Reading germline_control_1.dv_rescue.vcf.gz with NativeVcfReader

real	0m1.972s
user	0m5.181s
sys	0m9.344s