19:07:58 : INFO : -reading targets list: ctat_genome_lib_build_dir/ref_annot.gtf.mini.sortu
-mapping reads to genes

[330000], rate=19800000.00/min 
[340000], rate=20400000.00/min 
[350000], rate=21000000.00/min 
[360000], rate=21600000.00/min 
[370000], rate=22200000.00/min 
[380000], rate=22800000.00/min 
[390000], rate=23400000.00/min 
[400000], rate=24000000.00/min 
[410000], rate=24600000.00/min 
[420000], rate=25200000.00/min 
[430000], rate=25800000.00/min 
[440000], rate=26400000.00/min 
[450000], rate=27000000.00/min 
[460000], rate=27600000.00/min 
[470000], rate=28200000.00/min 
[480000], rate=28800000.00/min 
[490000], rate=29400000.00/min 
[500000], rate=30000000.00/min 
[510000], rate=30600000.00/min 
[520000], rate=31200000.00/min 
[530000], rate=31800000.00/min 
[540000], rate=32400000.00/min 
[550000], rate=33000000.00/min 
[560000], rate=33600000.00/min 
[570000], rate=34200000.00/min 
[580000], rate=34800000.00/min 
[590000], rate=35400000.00/min 
[600000], rate=36000000.00/min 
[610000], rate=36600000.00/min 
[620000], rate=37200000.00/min 
[630000], rate=37800000.00/min 
[640000], rate=38400000.00/min 
[650000], rate=39000000.00/min 
[660000], rate=39600000.00/min 
[670000], rate=40200000.00/min 
[680000], rate=40800000.00/min 
[690000], rate=41400000.00/min 
[700000], rate=42000000.00/min 
[710000], rate=42600000.00/min 
[720000], rate=43200000.00/min 
[730000], rate=43800000.00/min 
[740000], rate=44400000.00/min 
[750000], rate=22500000.00/min 
[760000], rate=22800000.00/min 
[770000], rate=23100000.00/min 
[780000], rate=23400000.00/min 
[790000], rate=23700000.00/min 
[800000], rate=24000000.00/min 
[810000], rate=24300000.00/min 
[820000], rate=24600000.00/min 
[830000], rate=24900000.00/min 
[840000], rate=25200000.00/min 
[850000], rate=25500000.00/min 
[860000], rate=25800000.00/min 
[870000], rate=26100000.00/min 
[880000], rate=26400000.00/min 
[890000], rate=26700000.00/min 
[900000], rate=27000000.00/min 
[910000], rate=27300000.00/min 
[920000], rate=27600000.00/min 
[930000], rate=27900000.00/min 
[940000], rate=28200000.00/min 
[950000], rate=28500000.00/min 
[960000], rate=28800000.00/min 
[970000], rate=29100000.00/min 
[980000], rate=29400000.00/min 
[990000], rate=29700000.00/min 
[1000000], rate=30000000.00/min 
[1010000], rate=30300000.00/min 
[1020000], rate=30600000.00/min 
[1030000], rate=30900000.00/min 
[1040000], rate=31200000.00/min 
[1050000], rate=31500000.00/min 
[1060000], rate=31800000.00/min 
[1070000], rate=32100000.00/min 
[1080000], rate=32400000.00/min 
[1090000], rate=32700000.00/min 
[1100000], rate=33000000.00/min 
[1110000], rate=33300000.00/min 
[1120000], rate=33600000.00/min 
[1130000], rate=33900000.00/min 
[1140000], rate=22800000.00/min 
[1150000], rate=23000000.00/min 
[1160000], rate=23200000.00/min 
[1170000], rate=23400000.00/min 
[1180000], rate=23600000.00/min 
[1190000], rate=23800000.00/min 
[1200000], rate=24000000.00/min 
[1210000], rate=24200000.00/min 
[1220000], rate=24400000.00/min 
[1230000], rate=24600000.00/min 
[1240000], rate=24800000.00/min 
[1250000], rate=25000000.00/min 
[1260000], rate=25200000.00/min 
[1270000], rate=25400000.00/min 
[1280000], rate=25600000.00/min 
[1290000], rate=25800000.00/min 
[1300000], rate=26000000.00/min 
[1310000], rate=26200000.00/min 
[1320000], rate=26400000.00/min 
[1330000], rate=26600000.00/min 
[1340000], rate=26800000.00/min 
[1350000], rate=27000000.00/min 
[1360000], rate=27200000.00/min 
[1370000], rate=27400000.00/min 
[1380000], rate=27600000.00/min 
[1390000], rate=27800000.00/min 
[1400000], rate=28000000.00/min 
[1410000], rate=28200000.00/min 
[1420000], rate=28400000.00/min 
[1430000], rate=28600000.00/min 
[1440000], rate=28800000.00/min 
[1450000], rate=29000000.00/min 
[1460000], rate=29200000.00/min 
[1470000], rate=29400000.00/min 
[1480000], rate=29600000.00/min 
[1490000], rate=29800000.00/min 
[1500000], rate=30000000.00/min 
[1510000], rate=30200000.00/min 
[1520000], rate=30400000.00/min 
[1530000], rate=30600000.00/min 
[1540000], rate=30800000.00/min 
[1550000], rate=31000000.00/min 
[1560000], rate=23400000.00/min 
[1570000], rate=23550000.00/min 
[1580000], rate=23700000.00/min 
[1590000], rate=23850000.00/min 
[1600000], rate=24000000.00/min 
[1610000], rate=24150000.00/min 
[1620000], rate=24300000.00/min 
[1630000], rate=24450000.00/min 
[1640000], rate=24600000.00/min 
[1650000], rate=24750000.00/min 
[1660000], rate=24900000.00/min 
[1670000], rate=25050000.00/min 
[1680000], rate=25200000.00/min 
[1690000], rate=25350000.00/min 
[1700000], rate=25500000.00/min 
[1710000], rate=25650000.00/min 
[1720000], rate=25800000.00/min 
[1730000], rate=25950000.00/min 
[1740000], rate=26100000.00/min 
[1750000], rate=26250000.00/min 19:08:07 : INFO : Running: /usr/local/src/CTAT-SPLICING/util/annotate_cancer_introns.pl --introns_file aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns  --ctat_genome_lib ctat_genome_lib_build_dir  --intron_col 0  > aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns.prelim 
Use of uninitialized value $ctat_genome_lib in concatenation (.) or string at /usr/local/src/CTAT-SPLICING/util/annotate_cancer_introns.pl line 18.
-aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns: identified 875 cancer introns
19:08:08 : INFO : Execution Time = 0.01 minutes. CMD: /usr/local/src/CTAT-SPLICING/util/annotate_cancer_introns.pl --introns_file aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns  --ctat_genome_lib ctat_genome_lib_build_dir  --intron_col 0  > aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns.prelim 
19:08:08 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/prelim_introns.ok
19:08:08 : INFO : Running: /usr/local/src/CTAT-SPLICING/util/filter_by_min_total_reads.py --cancer_intron_candidates aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns.prelim --min_total_reads 5  > aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns 
19:08:08 : INFO : Execution Time = 0.01 minutes. CMD: /usr/local/src/CTAT-SPLICING/util/filter_by_min_total_reads.py --cancer_intron_candidates aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns.prelim --min_total_reads 5  > aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns 
19:08:08 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/introns_filtered.ok
19:08:08 : INFO : -found 497 cancer introns
19:08:08 : INFO : Running: /usr/local/src/CTAT-SPLICING/util/make_igv_splice_bed.py --all_introns aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns  --cancer_introns aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns  --genome_lib_dir ctat_genome_lib_build_dir  --output_bed aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns.for_IGV.bed 
19:08:08 : INFO :  Creating the BED File.
19:08:10 : INFO : Saving Bed File as aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns.for_IGV.bed
19:08:10 : INFO : Execution Time = 0.03 minutes. CMD: /usr/local/src/CTAT-SPLICING/util/make_igv_splice_bed.py --all_introns aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns  --cancer_introns aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer.introns  --genome_lib_dir ctat_genome_lib_build_dir  --output_bed aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns.for_IGV.bed 
19:08:10 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/intron_igv_bed.ok
19:08:10 : INFO : Running: /usr/local/src/CTAT-SPLICING/util/igv_read_alignment_extractor.py --igv_introns_bed aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns.for_IGV.bed  --bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.Aligned.sortedByCoord.out.bam  --output_prefix aih-tih-sc-0754d2-R1_A23YTGFLT4_1 
[W::hts_idx_load3] The index file is older than the data file: aih-tih-sc-0754d2-R1_A23YTGFLT4_1.Aligned.sortedByCoord.out.bam.bai
19:08:51 : INFO : Execution Time = 0.68 minutes. CMD: /usr/local/src/CTAT-SPLICING/util/igv_read_alignment_extractor.py --igv_introns_bed aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns.for_IGV.bed  --bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.Aligned.sortedByCoord.out.bam  --output_prefix aih-tih-sc-0754d2-R1_A23YTGFLT4_1 
19:08:51 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/reads_alignments_extracted.ok
19:08:51 : INFO : Running: samtools sort -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer_intron_reads.sorted.bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer_intron_reads.bam
19:08:51 : INFO : Execution Time = 0.00 minutes. CMD: samtools sort -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer_intron_reads.sorted.bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer_intron_reads.bam
19:08:51 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/sort_cancer_intron_reads.ok
19:08:51 : INFO : Running: samtools sort -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.bam
[bam_sort_core] merging from 3 files and 1 in-memory blocks...
19:09:36 : INFO : Execution Time = 0.76 minutes. CMD: samtools sort -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.bam
19:09:36 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/sort_gene_reads.ok
19:09:36 : INFO : Running: /usr/local/src/CTAT-SPLICING/bamsifter/bamsifter -c 50  -i 50  -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam.tmp  --keep_secondary  aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.bam 
19:09:48 : INFO : Execution Time = 0.20 minutes. CMD: /usr/local/src/CTAT-SPLICING/bamsifter/bamsifter -c 50  -i 50  -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam.tmp  --keep_secondary  aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.bam 
19:09:48 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam.tmp.ok
19:09:48 : INFO : Running: samtools sort -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam.tmp
19:09:51 : INFO : Execution Time = 0.05 minutes. CMD: samtools sort -o aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam.tmp
19:09:51 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam.tmpsorted.ok
19:09:51 : INFO : Running: samtools index aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam 
19:09:51 : INFO : Execution Time = 0.01 minutes. CMD: samtools index aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam 
19:09:51 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.gene_reads.sorted.sifted.bam.indexed.ok
19:09:51 : INFO : Running: samtools index aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer_intron_reads.sorted.bam 
19:09:51 : INFO : Execution Time = 0.00 minutes. CMD: samtools index aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer_intron_reads.sorted.bam 
19:09:51 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.cancer_intron_reads.sorted.bam.indexed.ok
19:09:51 : INFO : Running: create_report aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns.for_IGV.bed  ctat_genome_lib_build_dir/ref_genome.fa  --type junction  --output aih-tih-sc-0754d2-R1_A23YTGFLT4_1.ctat-splicing.igv.html  --track-config aih-tih-sc-0754d2-R1_A23YTGFLT4_1.igv.tracks  --info-columns gene variant_name uniquely_mapped multi_mapped TCGA GTEx  --title 'CTAT_Splicing: aih-tih-sc-0754d2-R1_A23YTGFLT4_1' 
19:10:22 : INFO : Execution Time = 0.52 minutes. CMD: create_report aih-tih-sc-0754d2-R1_A23YTGFLT4_1.introns.for_IGV.bed  ctat_genome_lib_build_dir/ref_genome.fa  --type junction  --output aih-tih-sc-0754d2-R1_A23YTGFLT4_1.ctat-splicing.igv.html  --track-config aih-tih-sc-0754d2-R1_A23YTGFLT4_1.igv.tracks  --info-columns gene variant_name uniquely_mapped multi_mapped TCGA GTEx  --title 'CTAT_Splicing: aih-tih-sc-0754d2-R1_A23YTGFLT4_1' 
19:10:22 : INFO : Running: touch /tmp/nxf.cbcIA3qMJk/aih-tih-sc-0754d2-R1_A23YTGFLT4_1.chckpts/igv_create_html.ok
19:10:22 : INFO : done.