pandora_lib_promethion/slurm-2557974.out

WARNING: While bind mounting '/mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29:/mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29': destination is already in the mount point list

[COMMAND] /opt/bin/run_clairs --tumor_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam --normal_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --threads 40 --platform ont_r10_dorado_sup_5khz_ssrs --output_dir /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29 --region chr4:1-130874961 --sample_name CHAHA_diag --include_all_ctgs --print_germline_calls --enable_indel_calling --enable_clair3_germline_output --use_longphase_for_intermediate_haplotagging True 

[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/split_beds
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/candidates
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/pileup_tensor_can
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/fa_tensor_can
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/vcf_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/tmp_vcf_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/vcf
[INFO] --include_all_ctgs enabled
[INFO] Call variants in contigs: chr4
[INFO] Number of chunks for each contig: 39

[INFO] CALLER VERSION: 0.4.4
[INFO] NORMAL BAM FILE PATH: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam
[INFO] TUMOR BAM FILE PATH: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam
[INFO] REFERENCE FILE PATH: /home/t_steimle/ref/hs1/chm13v2.0.fa
[INFO] PLATFORM: ont_r10_dorado_sup_5khz_ssrs
[INFO] THREADS: 40
[INFO] OUTPUT FOLDER: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29
[INFO] OUTPUT VCF PATH: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/output.vcf.gz
[INFO] PILEUP MODEL PATH: /opt/conda/envs/clairs/bin/clairs_models/ont_r10_dorado_sup_5khz_ssrs/pileup.pkl
[INFO] FULL-ALIGNMENT MODEL PATH: /opt/conda/envs/clairs/bin/clairs_models/ont_r10_dorado_sup_5khz_ssrs/full_alignment.pkl
[INFO] BED FILE PATH: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/region.bed
[INFO] GENOTYPING MODE VCF FILE PATH: None
[INFO] HYBRID MODE VCF FILE PATH: None
[INFO] REGION FOR CALLING: chr4:1-130874961
[INFO] CONTIGS FOR CALLING: None
[INFO] CONDA BINARY PREFIX: /opt/conda/envs/clairs
[INFO] SAMTOOLS BINARY PATH: samtools
[INFO] PYTHON BINARY PATH: python3
[INFO] PYPY BINARY PATH: pypy3
[INFO] PARALLEL BINARY PATH: parallel
[INFO] LONGPHASE BINARY PATH: /opt/conda/envs/clairs/bin/longphase
[INFO] CHUNK SIZE: 5000000
[INFO] SNV MINIMUM AF: 0.05
[INFO] SNV MINIMUM QUAL: 8
[INFO] INDEL MINIMUM AF: 0.1
[INFO] INDEL PILEUP MODEL PATH: /opt/conda/envs/clairs/bin/clairs_models/ont_r10_dorado_sup_5khz_ssrs/indel/pileup.pkl
[INFO] INDEL FULL-ALIGNMENT MODEL PATH: /opt/conda/envs/clairs/bin/clairs_models/ont_r10_dorado_sup_5khz_ssrs/indel/full_alignment.pkl
[INFO] INDEL MINIMUM QUAL: 8
[INFO] NORMAL VCF FILE PATH: None
[INFO] DISABLE PHASING: False
[INFO] ENABLE DRY RUN: False
[INFO] ENABLE INDEL CALLING: True
[INFO] ENABLE PRINTING REFERENCE CALLS: False
[INFO] ENABLE PRINTING GERMLINE CALLS: True
[INFO] ENABLE INCLUDING ALL CTGS FOR CALLING: True
[INFO] ENABLE REMOVING INTERMEDIATE FILES: False

[INFO] Call Germline Variants in Normal BAM using Clair3
[INFO] RUN THE FOLLOWING COMMAND:
( /opt/conda/envs/clairs/bin/run_clair3.sh --bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --model_path /opt/conda/envs/clairs/bin/clairs_models/clair3_models/r1041_e82_400bps_sup_v420 --platform ont --threads 40 --output /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output --ctg_name=chr4 --samtools=samtools --pypy=pypy3 --python=python3 --min_coverage=4 --snp_min_af=0.08 --indel_min_af=0.15 --longphase_for_phasing  ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/1_CLAIR3_NORMAL.log

[INFO] CLAIR3 VERSION: v1.0.8
[INFO] BAM FILE PATH: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam
[INFO] REFERENCE FILE PATH: /home/t_steimle/ref/hs1/chm13v2.0.fa
[INFO] MODEL PATH: /opt/conda/envs/clairs/bin/clairs_models/clair3_models/r1041_e82_400bps_sup_v420
[INFO] OUTPUT FOLDER: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output
[INFO] PLATFORM: ont
[INFO] THREADS: 40
[INFO] BED FILE PATH: EMPTY
[INFO] VCF FILE PATH: EMPTY
[INFO] CONTIGS: chr4
[INFO] CONDA PREFIX: 
[INFO] SAMTOOLS PATH: samtools
[INFO] PYTHON PATH: python3
[INFO] PYPY PATH: pypy3
[INFO] PARALLEL PATH: parallel
[INFO] WHATSHAP PATH: whatshap
[INFO] LONGPHASE PATH: /opt/conda/envs/clairs/bin/longphase
[INFO] CHUNK SIZE: 5000000
[INFO] FULL ALIGN PROPORTION: 0.7
[INFO] FULL ALIGN REFERENCE PROPORTION: 0.1
[INFO] PHASING PROPORTION: 0.7
[INFO] MINIMUM MQ: 5
[INFO] MINIMUM COVERAGE: 4
[INFO] SNP AF THRESHOLD: 0.08
[INFO] INDEL AF THRESHOLD: 0.15
[INFO] BASE ERROR IN GVCF: 0.001
[INFO] GQ BIN SIZE IN GVCF: 5
[INFO] ENABLE FILEUP ONLY CALLING: False
[INFO] ENABLE FAST MODE CALLING: False
[INFO] ENABLE CALLING SNP CANDIDATES ONLY: False
[INFO] ENABLE PRINTING REFERENCE CALLS: False
[INFO] ENABLE OUTPUT GVCF: False
[INFO] ENABLE HAPLOID PRECISE MODE: False
[INFO] ENABLE HAPLOID SENSITIVE MODE: False
[INFO] ENABLE INCLUDE ALL CTGS CALLING: False
[INFO] ENABLE NO PHASING FOR FULL ALIGNMENT: False
[INFO] ENABLE REMOVING INTERMEDIATE FILES: False
[INFO] ENABLE LONGPHASE FOR INTERMEDIATE VCF PHASING: True
[INFO] ENABLE PHASING FINAL VCF OUTPUT USING WHATSHAP: False
[INFO] ENABLE PHASING FINAL VCF OUTPUT USING LONGPHASE: False
[INFO] ENABLE HAPLOTAGGING FINAL BAM: False
[INFO] ENABLE LONG INDEL CALLING: False
[INFO] ENABLE C_IMPLEMENT: True

+ /opt/conda/envs/clairs/bin/scripts/clair3_c_impl.sh --bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --threads 40 --model_path /opt/conda/envs/clairs/bin/clairs_models/clair3_models/r1041_e82_400bps_sup_v420 --platform ont --output /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output --bed_fn=EMPTY --vcf_fn=EMPTY --ctg_name=chr4 --sample_name=SAMPLE --chunk_num=0 --chunk_size=5000000 --samtools=samtools --python=python3 --pypy=pypy3 --parallel=parallel --whatshap=whatshap --qual=2 --var_pct_full=0.7 --ref_pct_full=0.1 --var_pct_phasing=0.7 --snp_min_af=0.08 --indel_min_af=0.15 --min_mq=5 --min_coverage=4 --min_contig_size=0 --pileup_only=False --gvcf=False --base_err=0.001 --gq_bin_size=5 --fast_mode=False --call_snp_only=False --print_ref_calls=False --haploid_precise=False --haploid_sensitive=False --include_all_ctgs=False --no_phasing_for_fa=False --pileup_model_prefix=pileup --fa_model_prefix=full_alignment --remove_intermediate_dir=False --enable_phasing=False --enable_long_indel=False --keep_iupac_bases=False --use_gpu=False --longphase_for_phasing=True --longphase=/opt/conda/envs/clairs/bin/longphase --use_whatshap_for_intermediate_phasing=True --use_longphase_for_intermediate_phasing=True --use_whatshap_for_final_output_phasing=False --use_longphase_for_final_output_phasing=False --use_whatshap_for_final_output_haplotagging=False

[INFO] Check environment variables
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/log
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/pileup_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/merge_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/phase_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/gvcf_tmp_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/full_alignment_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/phase_output/phase_vcf
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/phase_output/phase_bam
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/full_alignment_output/candidate_bed
[INFO] Call variant in contigs: chr4
[INFO] Chunk number for each contig: 39
[INFO] 1/7 Call variants using pileup model
Calling variants ...
Total processed positions in chr4 (chunk 11/39) : 24000
Total time elapsed: 70.18 s
Calling variants ...
Total processed positions in chr4 (chunk 24/39) : 70453
Total time elapsed: 143.41 s
Calling variants ...
Total processed positions in chr4 (chunk 16/39) : 68268
Total time elapsed: 145.92 s
Calling variants ...
Total processed positions in chr4 (chunk 13/39) : 73534
Total time elapsed: 148.75 s
Calling variants ...
Total processed positions in chr4 (chunk 25/39) : 75406
Total time elapsed: 149.04 s
Calling variants ...
Total processed positions in chr4 (chunk 5/39) : 75668
Total time elapsed: 149.73 s
Calling variants ...
Total processed positions in chr4 (chunk 28/39) : 75230
Total time elapsed: 149.87 s
Calling variants ...
Total processed positions in chr4 (chunk 14/39) : 77473
Total time elapsed: 151.72 s
Calling variants ...
Total processed positions in chr4 (chunk 30/39) : 77091
Total time elapsed: 153.13 s
Calling variants ...
Total processed positions in chr4 (chunk 22/39) : 72618
Total time elapsed: 153.66 s
Calling variants ...
Total processed positions in chr4 (chunk 27/39) : 76194
Total time elapsed: 155.23 s
Calling variants ...
Total processed positions in chr4 (chunk 6/39) : 79146
Total time elapsed: 156.66 s
Calling variants ...
Total processed positions in chr4 (chunk 7/39) : 72299
Total time elapsed: 158.26 s
Calling variants ...
Total processed positions in chr4 (chunk 19/39) : 76183
Total time elapsed: 158.36 s
Calling variants ...
Total processed positions in chr4 (chunk 26/39) : 81483
Total time elapsed: 158.68 s
Calling variants ...
Total processed positions in chr4 (chunk 9/39) : 75607
Total time elapsed: 159.75 s
Calling variants ...
Total processed positions in chr4 (chunk 20/39) : 76838
Total time elapsed: 162.96 s
Calling variants ...
Total processed positions in chr4 (chunk 8/39) : 82598
Total time elapsed: 163.69 s
Calling variants ...
Total processed positions in chr4 (chunk 23/39) : 71595
Total time elapsed: 141.04 s
Calling variants ...
Total processed positions in chr4 (chunk 4/39) : 79537
Total time elapsed: 168.09 s
Calling variants ...
Total processed positions in chr4 (chunk 10/39) : 81660
Total time elapsed: 168.78 s
Calling variants ...
Total processed positions in chr4 (chunk 12/39) : 77912
Total time elapsed: 169.22 s
Calling variants ...
Total processed positions in chr4 (chunk 17/39) : 73881
Total time elapsed: 145.86 s
Calling variants ...
Total processed positions in chr4 (chunk 21/39) : 80640
Total time elapsed: 171.20 s
Calling variants ...
Total processed positions in chr4 (chunk 18/39) : 78644
Total time elapsed: 149.29 s
Calling variants ...
Total processed positions in chr4 (chunk 29/39) : 84342
Total time elapsed: 174.90 s
Calling variants ...
Total processed positions in chr4 (chunk 2/39) : 92265
Total time elapsed: 177.16 s
Calling variants ...
Total processed positions in chr4 (chunk 1/39) : 94679
Total time elapsed: 180.70 s
Calling variants ...
Total processed positions in chr4 (chunk 15/39) : 77480
Total time elapsed: 156.85 s
Calling variants ...
Total processed positions in chr4 (chunk 3/39) : 86674
Total time elapsed: 161.63 s
Calling variants ...
Total processed positions in chr4 (chunk 31/39) : 78672
Total time elapsed: 127.41 s
Calling variants ...
Total processed positions in chr4 (chunk 33/39) : 78533
Total time elapsed: 106.12 s
Calling variants ...
Total processed positions in chr4 (chunk 35/39) : 75009
Total time elapsed: 107.49 s
Calling variants ...
Total processed positions in chr4 (chunk 36/39) : 80260
Total time elapsed: 107.59 s
Calling variants ...
Total processed positions in chr4 (chunk 32/39) : 81846
Total time elapsed: 114.83 s
Calling variants ...
Total processed positions in chr4 (chunk 34/39) : 74811
Total time elapsed: 113.50 s
Calling variants ...
Total processed positions in chr4 (chunk 37/39) : 82261
Total time elapsed: 114.01 s
Calling variants ...
Total processed positions in chr4 (chunk 38/39) : 85427
Total time elapsed: 121.06 s
Calling variants ...
Total processed positions in chr4 (chunk 39/39) : 83447
Total time elapsed: 119.38 s

real	4m44.258s
user	90m33.855s
sys	5m26.005s

[INFO] 2/7 Select heterozygous SNP variants for Whatshap phasing and haplotagging
[INFO] Select heterozygous pileup variants exceeding phasing quality cutoff 16
[INFO] Total heterozygous SNP positions selected: chr4: 120251

real	0m7.056s
user	0m6.717s
sys	0m0.247s

[INFO] 3/7 Phase VCF file using LongPhase
LongPhase Ver 1.7

--- File Parameter --- 
SNP File      : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/phase_output/phase_vcf/chr4.vcf
SV  File      : 
MOD File      : 
REF File      : /home/t_steimle/ref/hs1/chm13v2.0.fa
Output Prefix : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/tmp/phase_output/phase_vcf/phased_chr4
Generate Dot  : False
BAM File      : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam 

--- Phasing Parameter --- 
Seq Platform       : ONT
Phase Indel        : False
Distance Threshold : 300000
Connect Adjacent   : 20
Edge Threshold     : 0.7
Mapping Quality    : 1
Variant Confidence : 0.75
ReadTag Confidence : 0.65

parsing VCF ... 0s
parsing SV VCF ... 0s
parsing Meth VCF ... 0s
reading reference ... 2s
(chr4,15s)
parsing total:  15s
merge results ... 0s
writeResult SNP ... 1s

total process: 18s

real	0m18.515s
user	0m34.635s
sys	0m2.785s

[INFO] 5/7 Select candidates for full-alignment calling
[INFO] Set variants quality cutoff 20.0
[INFO] Set reference calls quality cutoff 14.0
[INFO] Low quality reference calls to be processed in chr4: 266081
[INFO] Low quality variants to be processed in chr4: 239599

real	0m7.775s
user	0m7.257s
sys	0m0.410s

[INFO] 6/7 Call low-quality variants using full-alignment model
Calling variants ...
Total processed positions in chr4 (chunk 27/51) : 10000
Total time elapsed: 90.58 s
Calling variants ...
Total processed positions in chr4 (chunk 2/51) : 10000
Total time elapsed: 90.98 s
Calling variants ...
Total processed positions in chr4 (chunk 11/51) : 10000
Total time elapsed: 94.20 s
Calling variants ...
Total processed positions in chr4 (chunk 24/51) : 10000
Total time elapsed: 95.38 s
Calling variants ...
Total processed positions in chr4 (chunk 9/51) : 10000
Total time elapsed: 95.94 s
Calling variants ...
Total processed positions in chr4 (chunk 18/51) : 10000
Total time elapsed: 96.07 s
Calling variants ...
Total processed positions in chr4 (chunk 6/51) : 10000
Total time elapsed: 97.74 s
Calling variants ...
Total processed positions in chr4 (chunk 28/51) : 10000
Total time elapsed: 98.19 s
Calling variants ...
Total processed positions in chr4 (chunk 14/51) : 10000
Total time elapsed: 101.22 s
Calling variants ...
Total processed positions in chr4 (chunk 12/51) : 10000
Total time elapsed: 102.23 s
Calling variants ...
Total processed positions in chr4 (chunk 21/51) : 10000
Total time elapsed: 102.73 s
Calling variants ...
Total processed positions in chr4 (chunk 30/51) : 10000
Total time elapsed: 103.47 s
Calling variants ...
Total processed positions in chr4 (chunk 23/51) : 10000
Total time elapsed: 103.43 s
Calling variants ...
Total processed positions in chr4 (chunk 5/51) : 10000
Total time elapsed: 104.26 s
Calling variants ...
Total processed positions in chr4 (chunk 29/51) : 10000
Total time elapsed: 104.25 s
Calling variants ...
Total processed positions in chr4 (chunk 15/51) : 10000
Total time elapsed: 104.98 s
Calling variants ...
Total processed positions in chr4 (chunk 19/51) : 10000
Total time elapsed: 105.38 s
Calling variants ...
Total processed positions in chr4 (chunk 4/51) : 10000
Total time elapsed: 105.77 s
Calling variants ...
Total processed positions in chr4 (chunk 10/51) : 10000
Total time elapsed: 106.84 s
Calling variants ...
Total processed positions in chr4 (chunk 17/51) : 10000
Total time elapsed: 107.02 s
Calling variants ...
Total processed positions in chr4 (chunk 26/51) : 10000
Total time elapsed: 107.53 s
Calling variants ...
Total processed positions in chr4 (chunk 3/51) : 10000
Total time elapsed: 107.84 s
Calling variants ...
Total processed positions in chr4 (chunk 16/51) : 10000
Total time elapsed: 108.47 s
Calling variants ...
Total processed positions in chr4 (chunk 8/51) : 10000
Total time elapsed: 108.63 s
Calling variants ...
Total processed positions in chr4 (chunk 22/51) : 10000
Total time elapsed: 108.81 s
Calling variants ...
Total processed positions in chr4 (chunk 13/51) : 10000
Total time elapsed: 110.05 s
Calling variants ...
Total processed positions in chr4 (chunk 1/51) : 10000
Total time elapsed: 110.09 s
Calling variants ...
Total processed positions in chr4 (chunk 20/51) : 10000
Total time elapsed: 110.35 s
Calling variants ...
Total processed positions in chr4 (chunk 25/51) : 10000
Total time elapsed: 110.58 s
Calling variants ...
Total processed positions in chr4 (chunk 7/51) : 10000
Total time elapsed: 110.83 s
Calling variants ...
Total processed positions in chr4 (chunk 51/51) : 5680
Total time elapsed: 58.98 s
Calling variants ...
Total processed positions in chr4 (chunk 38/51) : 10000
Total time elapsed: 78.77 s
Calling variants ...
Total processed positions in chr4 (chunk 32/51) : 10000
Total time elapsed: 86.12 s
Calling variants ...
Total processed positions in chr4 (chunk 39/51) : 10000
Total time elapsed: 77.54 s
Calling variants ...
Total processed positions in chr4 (chunk 34/51) : 10000
Total time elapsed: 83.29 s
Calling variants ...
Total processed positions in chr4 (chunk 37/51) : 10000
Total time elapsed: 83.31 s
Calling variants ...
Total processed positions in chr4 (chunk 33/51) : 10000
Total time elapsed: 86.47 s
Calling variants ...
Total processed positions in chr4 (chunk 31/51) : 10000
Total time elapsed: 90.67 s
Calling variants ...
Total processed positions in chr4 (chunk 35/51) : 10000
Total time elapsed: 85.48 s
Calling variants ...
Total processed positions in chr4 (chunk 47/51) : 10000
Total time elapsed: 79.94 s
Calling variants ...
Total processed positions in chr4 (chunk 36/51) : 10000
Total time elapsed: 89.40 s
Calling variants ...
Total processed positions in chr4 (chunk 46/51) : 10000
Total time elapsed: 81.23 s
Calling variants ...
Total processed positions in chr4 (chunk 44/51) : 10000
Total time elapsed: 82.69 s
Calling variants ...
Total processed positions in chr4 (chunk 42/51) : 10000
Total time elapsed: 83.85 s
Calling variants ...
Total processed positions in chr4 (chunk 41/51) : 10000
Total time elapsed: 84.51 s
Calling variants ...
Total processed positions in chr4 (chunk 40/51) : 10000
Total time elapsed: 85.44 s
Calling variants ...
Total processed positions in chr4 (chunk 45/51) : 10000
Total time elapsed: 86.60 s
Calling variants ...
Total processed positions in chr4 (chunk 48/51) : 10000
Total time elapsed: 84.92 s
Calling variants ...
Total processed positions in chr4 (chunk 49/51) : 10000
Total time elapsed: 85.67 s
Calling variants ...
Total processed positions in chr4 (chunk 50/51) : 10000
Total time elapsed: 86.42 s
Calling variants ...
Total processed positions in chr4 (chunk 43/51) : 10000
Total time elapsed: 88.89 s

real	3m21.051s
user	78m38.604s
sys	4m48.871s

[INFO] 7/7 Merge pileup VCF and full-alignment VCF
[INFO] Pileup variants processed in chr4: 103037
[INFO] Full-alignment variants processed in chr4: 249575

real	0m10.582s
user	0m11.421s
sys	0m0.423s

[INFO] Finish calling, output file: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/merge_output.vcf.gz

real	9m26.550s
user	170m47.807s
sys	10m21.421s

[INFO] Call Germline Variant in Tumor BAM using Clair3
[INFO] RUN THE FOLLOWING COMMAND:
( /opt/conda/envs/clairs/bin/run_clair3.sh --bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --model_path /opt/conda/envs/clairs/bin/clairs_models/clair3_models/r1041_e82_400bps_sup_v420 --platform ont --threads 40 --output /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output --ctg_name=chr4 --samtools=samtools --pypy=pypy3 --python=python3 --min_coverage=4 --snp_min_af=0.08 --indel_min_af=0.15 --longphase_for_phasing  ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/2_CLAIR3_TUMOR.log

[INFO] CLAIR3 VERSION: v1.0.8
[INFO] BAM FILE PATH: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam
[INFO] REFERENCE FILE PATH: /home/t_steimle/ref/hs1/chm13v2.0.fa
[INFO] MODEL PATH: /opt/conda/envs/clairs/bin/clairs_models/clair3_models/r1041_e82_400bps_sup_v420
[INFO] OUTPUT FOLDER: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output
[INFO] PLATFORM: ont
[INFO] THREADS: 40
[INFO] BED FILE PATH: EMPTY
[INFO] VCF FILE PATH: EMPTY
[INFO] CONTIGS: chr4
[INFO] CONDA PREFIX: 
[INFO] SAMTOOLS PATH: samtools
[INFO] PYTHON PATH: python3
[INFO] PYPY PATH: pypy3
[INFO] PARALLEL PATH: parallel
[INFO] WHATSHAP PATH: whatshap
[INFO] LONGPHASE PATH: /opt/conda/envs/clairs/bin/longphase
[INFO] CHUNK SIZE: 5000000
[INFO] FULL ALIGN PROPORTION: 0.7
[INFO] FULL ALIGN REFERENCE PROPORTION: 0.1
[INFO] PHASING PROPORTION: 0.7
[INFO] MINIMUM MQ: 5
[INFO] MINIMUM COVERAGE: 4
[INFO] SNP AF THRESHOLD: 0.08
[INFO] INDEL AF THRESHOLD: 0.15
[INFO] BASE ERROR IN GVCF: 0.001
[INFO] GQ BIN SIZE IN GVCF: 5
[INFO] ENABLE FILEUP ONLY CALLING: False
[INFO] ENABLE FAST MODE CALLING: False
[INFO] ENABLE CALLING SNP CANDIDATES ONLY: False
[INFO] ENABLE PRINTING REFERENCE CALLS: False
[INFO] ENABLE OUTPUT GVCF: False
[INFO] ENABLE HAPLOID PRECISE MODE: False
[INFO] ENABLE HAPLOID SENSITIVE MODE: False
[INFO] ENABLE INCLUDE ALL CTGS CALLING: False
[INFO] ENABLE NO PHASING FOR FULL ALIGNMENT: False
[INFO] ENABLE REMOVING INTERMEDIATE FILES: False
[INFO] ENABLE LONGPHASE FOR INTERMEDIATE VCF PHASING: True
[INFO] ENABLE PHASING FINAL VCF OUTPUT USING WHATSHAP: False
[INFO] ENABLE PHASING FINAL VCF OUTPUT USING LONGPHASE: False
[INFO] ENABLE HAPLOTAGGING FINAL BAM: False
[INFO] ENABLE LONG INDEL CALLING: False
[INFO] ENABLE C_IMPLEMENT: True

+ /opt/conda/envs/clairs/bin/scripts/clair3_c_impl.sh --bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --threads 40 --model_path /opt/conda/envs/clairs/bin/clairs_models/clair3_models/r1041_e82_400bps_sup_v420 --platform ont --output /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output --bed_fn=EMPTY --vcf_fn=EMPTY --ctg_name=chr4 --sample_name=SAMPLE --chunk_num=0 --chunk_size=5000000 --samtools=samtools --python=python3 --pypy=pypy3 --parallel=parallel --whatshap=whatshap --qual=2 --var_pct_full=0.7 --ref_pct_full=0.1 --var_pct_phasing=0.7 --snp_min_af=0.08 --indel_min_af=0.15 --min_mq=5 --min_coverage=4 --min_contig_size=0 --pileup_only=False --gvcf=False --base_err=0.001 --gq_bin_size=5 --fast_mode=False --call_snp_only=False --print_ref_calls=False --haploid_precise=False --haploid_sensitive=False --include_all_ctgs=False --no_phasing_for_fa=False --pileup_model_prefix=pileup --fa_model_prefix=full_alignment --remove_intermediate_dir=False --enable_phasing=False --enable_long_indel=False --keep_iupac_bases=False --use_gpu=False --longphase_for_phasing=True --longphase=/opt/conda/envs/clairs/bin/longphase --use_whatshap_for_intermediate_phasing=True --use_longphase_for_intermediate_phasing=True --use_whatshap_for_final_output_phasing=False --use_longphase_for_final_output_phasing=False --use_whatshap_for_final_output_haplotagging=False

[INFO] Check environment variables
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/log
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/pileup_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/merge_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/phase_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/gvcf_tmp_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/full_alignment_output
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/phase_output/phase_vcf
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/phase_output/phase_bam
[INFO] Create folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/full_alignment_output/candidate_bed
[INFO] Call variant in contigs: chr4
[INFO] Chunk number for each contig: 39
[INFO] 1/7 Call variants using pileup model
Calling variants ...
Total processed positions in chr4 (chunk 17/39) : 6938
Total time elapsed: 97.96 s
Calling variants ...
Total processed positions in chr4 (chunk 30/39) : 6275
Total time elapsed: 97.48 s
Calling variants ...
Total processed positions in chr4 (chunk 22/39) : 7168
Total time elapsed: 98.65 s
Calling variants ...
Total processed positions in chr4 (chunk 24/39) : 8033
Total time elapsed: 101.32 s
Calling variants ...
Total processed positions in chr4 (chunk 4/39) : 8859
Total time elapsed: 101.78 s
Calling variants ...
Total processed positions in chr4 (chunk 27/39) : 10107
Total time elapsed: 104.20 s
Calling variants ...
Total processed positions in chr4 (chunk 19/39) : 10456
Total time elapsed: 105.48 s
Calling variants ...
Total processed positions in chr4 (chunk 28/39) : 11973
Total time elapsed: 106.60 s
Calling variants ...
Total processed positions in chr4 (chunk 7/39) : 11742
Total time elapsed: 107.70 s
Calling variants ...
Total processed positions in chr4 (chunk 14/39) : 11319
Total time elapsed: 107.88 s
Calling variants ...
Total processed positions in chr4 (chunk 3/39) : 12191
Total time elapsed: 108.00 s
Calling variants ...
Total processed positions in chr4 (chunk 13/39) : 12378
Total time elapsed: 108.85 s
Calling variants ...
Total processed positions in chr4 (chunk 8/39) : 14322
Total time elapsed: 109.55 s
Calling variants ...
Total processed positions in chr4 (chunk 25/39) : 12826
Total time elapsed: 109.58 s
Calling variants ...
Total processed positions in chr4 (chunk 1/39) : 16761
Total time elapsed: 115.41 s
Calling variants ...
Total processed positions in chr4 (chunk 2/39) : 19043
Total time elapsed: 116.88 s
Calling variants ...
Total processed positions in chr4 (chunk 12/39) : 25433
Total time elapsed: 124.54 s
Calling variants ...
Total processed positions in chr4 (chunk 23/39) : 6875
Total time elapsed: 51.25 s
Calling variants ...
Total processed positions in chr4 (chunk 5/39) : 7383
Total time elapsed: 52.95 s
Calling variants ...
Total processed positions in chr4 (chunk 26/39) : 9155
Total time elapsed: 53.62 s
Calling variants ...
Total processed positions in chr4 (chunk 21/39) : 9342
Total time elapsed: 54.15 s
Calling variants ...
Total processed positions in chr4 (chunk 16/39) : 9070
Total time elapsed: 54.90 s
Calling variants ...
Total processed positions in chr4 (chunk 29/39) : 9144
Total time elapsed: 55.66 s
Calling variants ...
Total processed positions in chr4 (chunk 9/39) : 9194
Total time elapsed: 56.32 s
Calling variants ...
Total processed positions in chr4 (chunk 20/39) : 9952
Total time elapsed: 59.17 s
Calling variants ...
Total processed positions in chr4 (chunk 18/39) : 10631
Total time elapsed: 59.37 s
Calling variants ...
Total processed positions in chr4 (chunk 6/39) : 10917
Total time elapsed: 60.33 s
Calling variants ...
Total processed positions in chr4 (chunk 10/39) : 13221
Total time elapsed: 62.54 s
Calling variants ...
Total processed positions in chr4 (chunk 31/39) : 9517
Total time elapsed: 50.48 s
Calling variants ...
Total processed positions in chr4 (chunk 32/39) : 10951
Total time elapsed: 51.58 s
Calling variants ...
Total processed positions in chr4 (chunk 33/39) : 11317
Total time elapsed: 50.80 s
Calling variants ...
Total processed positions in chr4 (chunk 15/39) : 18241
Total time elapsed: 68.67 s
Calling variants ...
Total processed positions in chr4 (chunk 35/39) : 10750
Total time elapsed: 50.93 s
Calling variants ...
Total processed positions in chr4 (chunk 34/39) : 12049
Total time elapsed: 52.42 s
Calling variants ...
Total processed positions in chr4 (chunk 36/39) : 10096
Total time elapsed: 49.80 s
Calling variants ...
Total processed positions in chr4 (chunk 37/39) : 11340
Total time elapsed: 49.39 s
Calling variants ...
Total processed positions in chr4 (chunk 38/39) : 12999
Total time elapsed: 51.90 s
Calling variants ...
Total processed positions in chr4 (chunk 39/39) : 21385
Total time elapsed: 61.33 s
Calling variants ...
Total processed positions in chr4 (chunk 11/39) : 59320
Total time elapsed: 182.79 s

real	3m6.972s
user	35m10.970s
sys	16m37.256s

[INFO] 2/7 Select heterozygous SNP variants for Whatshap phasing and haplotagging
[INFO] Select heterozygous pileup variants exceeding phasing quality cutoff 20
[INFO] Total heterozygous SNP positions selected: chr4: 125541

real	0m2.138s
user	0m1.875s
sys	0m0.182s

[INFO] 3/7 Phase VCF file using LongPhase
LongPhase Ver 1.7

--- File Parameter --- 
SNP File      : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/phase_output/phase_vcf/chr4.vcf
SV  File      : 
MOD File      : 
REF File      : /home/t_steimle/ref/hs1/chm13v2.0.fa
Output Prefix : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/tmp/phase_output/phase_vcf/phased_chr4
Generate Dot  : False
BAM File      : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam 

--- Phasing Parameter --- 
Seq Platform       : ONT
Phase Indel        : False
Distance Threshold : 300000
Connect Adjacent   : 20
Edge Threshold     : 0.7
Mapping Quality    : 1
Variant Confidence : 0.75
ReadTag Confidence : 0.65

parsing VCF ... 0s
parsing SV VCF ... 0s
parsing Meth VCF ... 0s
reading reference ... 2s
(chr4,77s)
parsing total:  77s
merge results ... 0s
writeResult SNP ... 1s

total process: 80s

real	1m20.651s
user	2m23.459s
sys	0m9.362s

[INFO] 5/7 Select candidates for full-alignment calling
[INFO] Set variants quality cutoff 22.0
[INFO] Set reference calls quality cutoff 7.0
[INFO] Low quality reference calls to be processed in chr4: 15242
[INFO] Low quality variants to be processed in chr4: 242179

real	0m2.055s
user	0m1.823s
sys	0m0.180s

[INFO] 6/7 Call low-quality variants using full-alignment model
Calling variants ...
Total processed positions in chr4 (chunk 26/26) : 7421
Total time elapsed: 98.11 s
Calling variants ...
Total processed positions in chr4 (chunk 8/26) : 10000
Total time elapsed: 99.93 s
Calling variants ...
Total processed positions in chr4 (chunk 2/26) : 10000
Total time elapsed: 106.12 s
Calling variants ...
Total processed positions in chr4 (chunk 1/26) : 10000
Total time elapsed: 112.32 s
Calling variants ...
Total processed positions in chr4 (chunk 24/26) : 10000
Total time elapsed: 116.91 s
Calling variants ...
Total processed positions in chr4 (chunk 9/26) : 10000
Total time elapsed: 123.12 s
Calling variants ...
Total processed positions in chr4 (chunk 11/26) : 10000
Total time elapsed: 125.15 s
Calling variants ...
Total processed positions in chr4 (chunk 10/26) : 10000
Total time elapsed: 129.96 s
Calling variants ...
Total processed positions in chr4 (chunk 22/26) : 10000
Total time elapsed: 129.91 s
Calling variants ...
Total processed positions in chr4 (chunk 7/26) : 10000
Total time elapsed: 130.76 s
Calling variants ...
Total processed positions in chr4 (chunk 17/26) : 10000
Total time elapsed: 131.61 s
Calling variants ...
Total processed positions in chr4 (chunk 25/26) : 10000
Total time elapsed: 132.40 s
Calling variants ...
Total processed positions in chr4 (chunk 12/26) : 10000
Total time elapsed: 133.40 s
Calling variants ...
Total processed positions in chr4 (chunk 3/26) : 10000
Total time elapsed: 133.90 s
Calling variants ...
Total processed positions in chr4 (chunk 21/26) : 10000
Total time elapsed: 134.24 s
Calling variants ...
Total processed positions in chr4 (chunk 23/26) : 10000
Total time elapsed: 134.58 s
Calling variants ...
Total processed positions in chr4 (chunk 6/26) : 10000
Total time elapsed: 134.47 s
Calling variants ...
Total processed positions in chr4 (chunk 5/26) : 10000
Total time elapsed: 135.31 s
Calling variants ...
Total processed positions in chr4 (chunk 15/26) : 10000
Total time elapsed: 136.86 s
Calling variants ...
Total processed positions in chr4 (chunk 14/26) : 10000
Total time elapsed: 137.60 s
Calling variants ...
Total processed positions in chr4 (chunk 19/26) : 10000
Total time elapsed: 140.33 s
Calling variants ...
Total processed positions in chr4 (chunk 20/26) : 10000
Total time elapsed: 141.75 s
Calling variants ...
Total processed positions in chr4 (chunk 13/26) : 10000
Total time elapsed: 141.61 s
Calling variants ...
Total processed positions in chr4 (chunk 18/26) : 10000
Total time elapsed: 148.75 s
Calling variants ...
Total processed positions in chr4 (chunk 4/26) : 10000
Total time elapsed: 161.91 s
Calling variants ...
Total processed positions in chr4 (chunk 16/26) : 10000
Total time elapsed: 174.46 s

real	2m58.186s
user	53m55.414s
sys	2m45.006s

[INFO] 7/7 Merge pileup VCF and full-alignment VCF
[INFO] Pileup variants processed in chr4: 104058
[INFO] Full-alignment variants processed in chr4: 223475

real	0m3.608s
user	0m3.707s
sys	0m0.216s

[INFO] Finish calling, output file: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/merge_output.vcf.gz

real	7m46.215s
user	91m47.732s
sys	19m33.629s

[INFO] Select Heterozygous SNP for Phasing
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/parallel_1_select_hetero_snp_for_phasing.log -j 40 pypy3 /opt/bin/clairs.py select_hetero_snp_for_phasing --tumor_vcf_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_tumor_output/merge_output.vcf.gz --normal_vcf_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/clair3_normal_output/merge_output.vcf.gz --output_folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/vcf --ctg_name {1} --use_heterozygous_snp_in_normal_sample_for_intermediate_phasing True :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CONTIGS ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/1_select_hetero_snp_for_phasing.log

[INFO] Total HET SNP calls selected: chr4: 162879, not found:920, not match:65, low_qual_count:0. Total normal:165926 Total tumor:163864, pro: 0.994

[INFO] Phase the Tumor BAM
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/parallel_4_phase_tumor.log -j 40 /opt/conda/envs/clairs/bin/longphase phase  -s /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/vcf/{1}.vcf -b /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam -r /home/t_steimle/ref/hs1/chm13v2.0.fa -t 40 -o /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_phased_{1} --ont :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CONTIGS && parallel -j 40 bgzip -f /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_phased_{1}.vcf :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CONTIGS ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/4_phase_tumor.log && parallel -j 40 tabix -f -p vcf /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_phased_{1}.vcf.gz :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CONTIGS

LongPhase Ver 1.7

--- File Parameter --- 
SNP File      : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/vcf/chr4.vcf
SV  File      : 
MOD File      : 
REF File      : /home/t_steimle/ref/hs1/chm13v2.0.fa
Output Prefix : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_phased_chr4
Generate Dot  : False
BAM File      : /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam 

--- Phasing Parameter --- 
Seq Platform       : ONT
Phase Indel        : False
Distance Threshold : 300000
Connect Adjacent   : 20
Edge Threshold     : 0.7
Mapping Quality    : 1
Variant Confidence : 0.75
ReadTag Confidence : 0.65

parsing VCF ... 1s
parsing SV VCF ... 0s
parsing Meth VCF ... 0s
reading reference ... 2s
(chr4,81s)
parsing total:  81s
merge results ... 0s
writeResult SNP ... 2s

total process: 86s

[INFO] Haplotag the Tumor BAM
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/parallel_5_haplotag_tumor.log -j 40 /opt/conda/envs/clairs/bin/longphase haplotag -o /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_{1} --reference /home/t_steimle/ref/hs1/chm13v2.0.fa --region {1}  -s /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_phased_{1}.vcf.gz -b /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CONTIGS ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/clair3_log/5_tumor_haplotag.log && parallel -j 40 samtools index  -@40 /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_{1}.bam :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CONTIGS

phased SNP file:   /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_phased_chr4.vcf.gz
phased SV file:    
phased MOD file:   
input bam file:    /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam
input ref file:    /home/t_steimle/ref/hs1/chm13v2.0.fa
output bam file:   /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_chr4.bam
number of threads: 1
write log file:    false
log file:          
-------------------------------------------
tag region:                    chr4
filter mapping quality below:  1
percentage threshold:          0.6
tag supplementary:             false
-------------------------------------------
parsing SNP VCF ... 1s
tag read start ...
chr: chr4 ... 1638s
tag read 1641s
-------------------------------------------
total process time:  1642s
total alignment:     2126232
total supplementary: 91198
total secondary:     0
total unmapped:      0
total tag alignment: 1100175
total untagged:      1026057

[INFO] STEP 1: Extract Variant Candidates from Tumor and Normal BAMs
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/parallel_1_extract_tumor_candidates.log -C " " -j 40 pypy3 /opt/bin/clairs.py extract_pair_candidates --tumor_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam --normal_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --samtools samtools --snv_min_af 0.05 --indel_min_af 0.1 --chunk_id {2}  --chunk_num {3}  --ctg_name {1}  --platform ont --min_coverage 4 --bed_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/split_beds/{1} --candidates_folder /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/candidates --output_depth True  --select_indel_candidates True --hybrid_mode_vcf_fn None --genotyping_mode_vcf_fn None :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CHUNK_LIST ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/1_EC.log && pypy3 /opt/bin/clairs.py concat_files --input_dir /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/candidates --input_prefix CANDIDATES_FILE_ --output_fn CANDIDATES_FILES 

[INFO] chr4 chunk 15/39: Total snv candidates found: 5441, total indel candidates found: 298
[INFO] chr4 chunk 16/39: Total snv candidates found: 4972, total indel candidates found: 649
[INFO] chr4 chunk 14/39: Total snv candidates found: 4283, total indel candidates found: 912
[INFO] chr4 chunk 2/39: Total snv candidates found: 1796, total indel candidates found: 885
[INFO] chr4 chunk 0/39: Total snv candidates found: 1735, total indel candidates found: 1346
[INFO] chr4 chunk 7/39: Total snv candidates found: 406, total indel candidates found: 909
[INFO] chr4 chunk 11/39: Total snv candidates found: 929, total indel candidates found: 1229
[INFO] chr4 chunk 1/39: Total snv candidates found: 1671, total indel candidates found: 996
[INFO] chr4 chunk 5/39: Total snv candidates found: 487, total indel candidates found: 731
[INFO] chr4 chunk 17/39: Total snv candidates found: 558, total indel candidates found: 942
[INFO] chr4 chunk 9/39: Total snv candidates found: 465, total indel candidates found: 653
[INFO] chr4 chunk 4/39: Total snv candidates found: 539, total indel candidates found: 726
[INFO] chr4 chunk 12/39: Total snv candidates found: 346, total indel candidates found: 805
[INFO] chr4 chunk 8/39: Total snv candidates found: 456, total indel candidates found: 662
[INFO] chr4 chunk 6/39: Total snv candidates found: 226, total indel candidates found: 558
[INFO] chr4 chunk 3/39: Total snv candidates found: 571, total indel candidates found: 719
[INFO] chr4 chunk 10/39: Total snv candidates found: 656, total indel candidates found: 662
[INFO] chr4 chunk 18/39: Total snv candidates found: 583, total indel candidates found: 644
[INFO] chr4 chunk 20/39: Total snv candidates found: 529, total indel candidates found: 620
[INFO] chr4 chunk 21/39: Total snv candidates found: 1317, total indel candidates found: 687
[INFO] chr4 chunk 13/39: Total snv candidates found: 294, total indel candidates found: 580
[INFO] chr4 chunk 34/39: Total snv candidates found: 257, total indel candidates found: 663
[INFO] chr4 chunk 31/39: Total snv candidates found: 276, total indel candidates found: 622
[INFO] chr4 chunk 22/39: Total snv candidates found: 287, total indel candidates found: 729
[INFO] chr4 chunk 38/39: Total snv candidates found: 366, total indel candidates found: 558
[INFO] chr4 chunk 25/39: Total snv candidates found: 527, total indel candidates found: 916
[INFO] chr4 chunk 33/39: Total snv candidates found: 379, total indel candidates found: 786
[INFO] chr4 chunk 26/39: Total snv candidates found: 875, total indel candidates found: 831
[INFO] chr4 chunk 37/39: Total snv candidates found: 391, total indel candidates found: 753
[INFO] chr4 chunk 27/39: Total snv candidates found: 538, total indel candidates found: 762
[INFO] chr4 chunk 19/39: Total snv candidates found: 351, total indel candidates found: 614
[INFO] chr4 chunk 23/39: Total snv candidates found: 458, total indel candidates found: 779
[INFO] chr4 chunk 32/39: Total snv candidates found: 210, total indel candidates found: 664
[INFO] chr4 chunk 35/39: Total snv candidates found: 344, total indel candidates found: 588
[INFO] chr4 chunk 24/39: Total snv candidates found: 277, total indel candidates found: 706
[INFO] chr4 chunk 28/39: Total snv candidates found: 439, total indel candidates found: 670
[INFO] chr4 chunk 29/39: Total snv candidates found: 588, total indel candidates found: 687
[INFO] chr4 chunk 30/39: Total snv candidates found: 416, total indel candidates found: 641
[INFO] chr4 chunk 36/39: Total snv candidates found: 736, total indel candidates found: 736

[INFO] STEP 2: Pileup Model Calling
[INFO] Create Paired Tensors
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/parallel_2-1_create_pair_tensor.log -j 40 pypy3 /opt/bin/clairs.py create_pair_tensor_pileup --normal_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam --tumor_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/CHAHA_diag_hs1.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --ctg_name {1/.} --samtools samtools --candidates_bed_regions {1} --tensor_can_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/pileup_tensor_can/{1/}  --platform ont :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/candidates/CANDIDATES_FILES ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/2-1_CPT.log

[INFO] chr4 chunk 1-1/34 Tensors generated: 257
[INFO] chr4 chunk 1-1/32 Tensors generated: 210
[INFO] chr4 chunk 1-1/24 Tensors generated: 276
[INFO] chr4 chunk 1-1/6 Tensors generated: 226
[INFO] chr4 chunk 1-1/31 Tensors generated: 275
[INFO] chr4 chunk 1-1/13 Tensors generated: 294
[INFO] chr4 chunk 1-1/22 Tensors generated: 287
[INFO] chr4 chunk 1-1/35 Tensors generated: 344
[INFO] chr4 chunk 1-1/12 Tensors generated: 340
[INFO] chr4 chunk 1-1/19 Tensors generated: 351
[INFO] chr4 chunk 1-1/38 Tensors generated: 366
[INFO] chr4 chunk 1-1/33 Tensors generated: 378
[INFO] chr4 chunk 1-1/7 Tensors generated: 406
[INFO] chr4 chunk 1-1/37 Tensors generated: 391
[INFO] chr4 chunk 1-1/23 Tensors generated: 458
[INFO] chr4 chunk 1-1/30 Tensors generated: 415
[INFO] chr4 chunk 1-1/9 Tensors generated: 465
[INFO] chr4 chunk 1-1/25 Tensors generated: 525
[INFO] chr4 chunk 1-1/28 Tensors generated: 439
[INFO] chr4 chunk 1-1/5 Tensors generated: 485
[INFO] chr4 chunk 1-1/8 Tensors generated: 456
[INFO] chr4 chunk 1-1/1 Tensors generated: 1671
[INFO] chr4 chunk 1-1/4 Tensors generated: 539
[INFO] chr4 chunk 1-1/29 Tensors generated: 588
[INFO] chr4 chunk 1-1/20 Tensors generated: 529
[INFO] chr4 chunk 1-1/27 Tensors generated: 538
[INFO] chr4 chunk 1-1/17 Tensors generated: 554
[INFO] chr4 chunk 1-1/18 Tensors generated: 583
[INFO] chr4 chunk 1-1/26 Tensors generated: 875
[INFO] chr4 chunk 1-1/3 Tensors generated: 569
[INFO] chr4 chunk 1-1/2 Tensors generated: 1780
[INFO] chr4 chunk 1-1/0 Tensors generated: 1732
[INFO] chr4 chunk 1-1/10 Tensors generated: 652
[INFO] chr4 chunk 1-1/36 Tensors generated: 736
[INFO] chr4 chunk 1-1/11 Tensors generated: 926
[INFO] chr4 chunk 1-1/21 Tensors generated: 1317
[INFO] chr4 chunk 1-1/15 Tensors generated: 5298
[INFO] chr4 chunk 1-1/14 Tensors generated: 4283
[INFO] chr4 chunk 1-1/16 Tensors generated: 4972

[INFO] Pileup Model Prediction
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/parallel_2-2_predict.log -j 40 python3 /opt/bin/clairs.py predict --tensor_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/pileup_tensor_can/{1/}  --call_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/vcf_output/p_{1/}.vcf --chkpnt_fn /opt/conda/envs/clairs/bin/clairs_models/ont_r10_dorado_sup_5khz_ssrs/pileup.pkl --use_gpu False --platform ont --ctg_name {1/.} --pileup  --show_germline  :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/candidates/CANDIDATES_FILES ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/2-2_PREDICT.log

[INFO] chr4 total processed positions: 226, time elapsed: 1.4s
[INFO] chr4 total processed positions: 210, time elapsed: 1.4s
[INFO] chr4 total processed positions: 294, time elapsed: 1.5s
[INFO] chr4 total processed positions: 257, time elapsed: 1.5s
[INFO] chr4 total processed positions: 275, time elapsed: 0.9s
[INFO] chr4 total processed positions: 287, time elapsed: 1.6s
[INFO] chr4 total processed positions: 340, time elapsed: 1.7s
[INFO] chr4 total processed positions: 276, time elapsed: 1.6s
[INFO] chr4 total processed positions: 366, time elapsed: 1.5s
[INFO] chr4 total processed positions: 344, time elapsed: 1.3s
[INFO] chr4 total processed positions: 378, time elapsed: 1.6s
[INFO] chr4 total processed positions: 351, time elapsed: 1.5s
[INFO] chr4 total processed positions: 439, time elapsed: 1.8s
[INFO] chr4 total processed positions: 406, time elapsed: 1.5s
[INFO] chr4 total processed positions: 458, time elapsed: 1.9s
[INFO] chr4 total processed positions: 415, time elapsed: 1.7s
[INFO] chr4 total processed positions: 456, time elapsed: 1.9s
[INFO] chr4 total processed positions: 391, time elapsed: 1.3s
[INFO] chr4 total processed positions: 529, time elapsed: 2.0s
[INFO] chr4 total processed positions: 554, time elapsed: 1.8s
[INFO] chr4 total processed positions: 465, time elapsed: 1.9s
[INFO] chr4 total processed positions: 539, time elapsed: 1.8s
[INFO] chr4 total processed positions: 485, time elapsed: 2.1s
[INFO] chr4 total processed positions: 525, time elapsed: 2.1s
[INFO] chr4 total processed positions: 538, time elapsed: 2.1s
[INFO] chr4 total processed positions: 569, time elapsed: 2.2s
[INFO] chr4 total processed positions: 583, time elapsed: 2.3s
[INFO] chr4 total processed positions: 736, time elapsed: 2.2s
[INFO] chr4 total processed positions: 588, time elapsed: 2.2s
[INFO] chr4 total processed positions: 652, time elapsed: 2.0s
[INFO] chr4 total processed positions: 875, time elapsed: 2.5s
[INFO] chr4 total processed positions: 926, time elapsed: 2.7s
[INFO] chr4 total processed positions: 1317, time elapsed: 3.4s
[INFO] chr4 total processed positions: 1671, time elapsed: 4.2s
[INFO] chr4 total processed positions: 1732, time elapsed: 4.0s
[INFO] chr4 total processed positions: 1780, time elapsed: 4.6s
[INFO] chr4 total processed positions: 4283, time elapsed: 9.3s
[INFO] chr4 total processed positions: 4972, time elapsed: 10.5s
[INFO] chr4 total processed positions: 5298, time elapsed: 11.5s

[INFO] Merge Pileup VCFs
[INFO] RUN THE FOLLOWING COMMAND:
pypy3 /opt/bin/clairs.py sort_vcf --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --contigs_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/CONTIGS --input_dir /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/vcf_output --vcf_fn_prefix p_ --output_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/vcf_output/pileup.vcf

[INFO] Sorting VCFs...
[INFO] Finished VCF sorting!

[INFO] STEP 3: Full-alignment Model Calling
[INFO] Create Full-alignment Paired Tensors
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/parallel_3-1_create_pair_tensor_fa.log -j 40 pypy3 /opt/bin/clairs.py create_pair_tensor --normal_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/norm/CHAHA_norm_hs1.bam --tumor_bam_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/clair3_output/phased_output/tumor_{1/.}.bam --ref_fn /home/t_steimle/ref/hs1/chm13v2.0.fa --ctg_name {1/.} --samtools samtools --candidates_bed_regions {1} --tensor_can_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/fa_tensor_can/{1/}  --platform ont :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/candidates/CANDIDATES_FILES ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/3-1_CPT.log

[INFO] chr4 chunk 1-1/32 Tensors generated: 210
[INFO] chr4 chunk 1-1/34 Tensors generated: 257
[INFO] chr4 chunk 1-1/6 Tensors generated: 226
[INFO] chr4 chunk 1-1/24 Tensors generated: 276
[INFO] chr4 chunk 1-1/22 Tensors generated: 287
[INFO] chr4 chunk 1-1/31 Tensors generated: 275
[INFO] chr4 chunk 1-1/13 Tensors generated: 294
[INFO] chr4 chunk 1-1/12 Tensors generated: 340
[INFO] chr4 chunk 1-1/35 Tensors generated: 344
[INFO] chr4 chunk 1-1/33 Tensors generated: 378
[INFO] chr4 chunk 1-1/7 Tensors generated: 406
[INFO] chr4 chunk 1-1/19 Tensors generated: 351
[INFO] chr4 chunk 1-1/38 Tensors generated: 366
[INFO] chr4 chunk 1-1/37 Tensors generated: 391
[INFO] chr4 chunk 1-1/23 Tensors generated: 458
[INFO] chr4 chunk 1-1/30 Tensors generated: 415
[INFO] chr4 chunk 1-1/9 Tensors generated: 465
[INFO] chr4 chunk 1-1/28 Tensors generated: 439
[INFO] chr4 chunk 1-1/5 Tensors generated: 485
[INFO] chr4 chunk 1-1/8 Tensors generated: 456
[INFO] chr4 chunk 1-1/4 Tensors generated: 539
[INFO] chr4 chunk 1-1/25 Tensors generated: 525
[INFO] chr4 chunk 1-1/27 Tensors generated: 538
[INFO] chr4 chunk 1-1/20 Tensors generated: 529
[INFO] chr4 chunk 1-1/17 Tensors generated: 554
[INFO] chr4 chunk 1-1/29 Tensors generated: 588
[INFO] chr4 chunk 1-1/18 Tensors generated: 583
[INFO] chr4 chunk 1-1/3 Tensors generated: 569
[INFO] chr4 chunk 1-1/10 Tensors generated: 652
[INFO] chr4 chunk 1-1/36 Tensors generated: 736
[INFO] chr4 chunk 1-1/26 Tensors generated: 875
[INFO] chr4 chunk 1-1/11 Tensors generated: 926
[INFO] chr4 chunk 1-1/1 Tensors generated: 1671
[INFO] chr4 chunk 1-1/21 Tensors generated: 1317
[INFO] chr4 chunk 1-1/2 Tensors generated: 1747
[INFO] chr4 chunk 1-1/0 Tensors generated: 1672
[INFO] chr4 chunk 1-1/15 Tensors generated: 4912
[INFO] chr4 chunk 1-1/16 Tensors generated: 4699
[INFO] chr4 chunk 1-1/14 Tensors generated: 4228

[INFO] Full-alignment Model Prediction
[INFO] RUN THE FOLLOWING COMMAND:
( parallel --joblog /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/parallel_3-2_predict.log -j 40 python3 /opt/bin/clairs.py predict --tensor_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/fa_tensor_can/{1/}  --call_fn /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/vcf_output/fa_{1/}.vcf --chkpnt_fn /opt/conda/envs/clairs/bin/clairs_models/ont_r10_dorado_sup_5khz_ssrs/full_alignment.pkl --use_gpu False --platform ont --ctg_name {1/.} --show_germline  :::: /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/tmp/candidates/CANDIDATES_FILES ) 2>&1 | tee /mnt/beegfs02/scratch/t_steimle/data/wgs/CHAHA/diag/ClairS/part29/logs/3-2_PREDICT.log

[INFO] chr4 total processed positions: 210, time elapsed: 27.7s
[INFO] chr4 total processed positions: 226, time elapsed: 29.5s
[INFO] chr4 total processed positions: 257, time elapsed: 33.4s
[INFO] chr4 total processed positions: 276, time elapsed: 36.2s
[INFO] chr4 total processed positions: 275, time elapsed: 35.9s
[INFO] chr4 total processed positions: 287, time elapsed: 37.5s
[INFO] chr4 total processed positions: 294, time elapsed: 38.1s
[INFO] chr4 total processed positions: 340, time elapsed: 44.0s
[INFO] chr4 total processed positions: 344, time elapsed: 44.8s
[INFO] chr4 total processed positions: 351, time elapsed: 44.5s
[INFO] chr4 total processed positions: 366, time elapsed: 47.8s
[INFO] chr4 total processed positions: 378, time elapsed: 49.1s
[INFO] chr4 total processed positions: 415, time elapsed: 50.2s
[INFO] chr4 total processed positions: 391, time elapsed: 50.6s
[INFO] chr4 total processed positions: 406, time elapsed: 52.5s
[INFO] chr4 total processed positions: 439, time elapsed: 54.2s
[INFO] chr4 total processed positions: 458, time elapsed: 56.5s
[INFO] chr4 total processed positions: 465, time elapsed: 57.0s
[INFO] chr4 total processed positions: 456, time elapsed: 57.2s
[INFO] chr4 total processed positions: 485, time elapsed: 59.2s
[INFO] chr4 total processed positions: 525, time elapsed: 63.9s
[INFO] chr4 total processed positions: 529, time elapsed: 65.8s
[INFO] chr4 total processed positions: 539, time elapsed: 66.4s
[INFO] chr4 total processed positions: 538, time elapsed: 67.0s
[INFO] chr4 total processed positions: 554, time elapsed: 69.8s
[INFO] chr4 total processed positions: 569, time elapsed: 71.7s
[INFO] chr4 total processed positions: 588, time elapsed: 73.2s
[INFO] chr4 total processed positions: 583, time elapsed: 73.6s
[INFO] chr4 total processed positions: 652, time elapsed: 81.3s
[INFO] chr4 total processed positions: 736, time elapsed: 90.3s
[INFO] chr4 total processed positions: 875, time elapsed: 109.0s
[INFO] chr4 total processed positions: 926, time elapsed: 110.2s
[INFO] chr4 total processed positions: 1317, time elapsed: 158.1s
[INFO] chr4 total processed positions: 1671, time elapsed: 197.4s
[INFO] chr4 total processed positions: 1672, time elapsed: 201.5s
[INFO] chr4 total processed positions: 1747, time elapsed: 208.0s