This page was generated on 2019-04-16 11:49:46 -0400 (Tue, 16 Apr 2019).
HTSeqGenie 4.12.0 Jens Reeder
Snapshot Date: 2019-04-15 17:01:12 -0400 (Mon, 15 Apr 2019) |
URL: https://git.bioconductor.org/packages/HTSeqGenie |
Branch: RELEASE_3_8 |
Last Commit: 56fca6c |
Last Changed Date: 2018-10-30 11:41:49 -0400 (Tue, 30 Oct 2018) |
| malbec1 | Linux (Ubuntu 16.04.6 LTS) / x86_64 | OK | OK | [ OK ] | | |
merida1 | OS X 10.11.6 El Capitan / x86_64 | ...NOT SUPPORTED... |
R version 3.5.3 (2019-03-11) -- "Great Truth"
Copyright (C) 2019 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu (64-bit)
R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.
R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.
Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.
> library("HTSeqGenie")
Loading required package: gmapR
Loading required package: GenomeInfoDb
Loading required package: BiocGenerics
Loading required package: parallel
Attaching package: 'BiocGenerics'
The following objects are masked from 'package:parallel':
clusterApply, clusterApplyLB, clusterCall, clusterEvalQ,
clusterExport, clusterMap, parApply, parCapply, parLapply,
parLapplyLB, parRapply, parSapply, parSapplyLB
The following objects are masked from 'package:stats':
IQR, mad, sd, var, xtabs
The following objects are masked from 'package:base':
Filter, Find, Map, Position, Reduce, anyDuplicated, append,
as.data.frame, basename, cbind, colMeans, colSums, colnames,
dirname, do.call, duplicated, eval, evalq, get, grep, grepl,
intersect, is.unsorted, lapply, lengths, mapply, match, mget,
order, paste, pmax, pmax.int, pmin, pmin.int, rank, rbind,
rowMeans, rowSums, rownames, sapply, setdiff, sort, table, tapply,
union, unique, unsplit, which, which.max, which.min
Loading required package: S4Vectors
Loading required package: stats4
Attaching package: 'S4Vectors'
The following object is masked from 'package:base':
expand.grid
Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector
Attaching package: 'Biostrings'
The following object is masked from 'package:base':
strsplit
Loading required package: ShortRead
Loading required package: BiocParallel
Loading required package: GenomicAlignments
Loading required package: SummarizedExperiment
Loading required package: Biobase
Welcome to Bioconductor
Vignettes contain introductory material; view with
'browseVignettes()'. To cite Bioconductor, see
'citation("Biobase")', and for packages 'citation("pkgname")'.
Loading required package: DelayedArray
Loading required package: matrixStats
Attaching package: 'matrixStats'
The following objects are masked from 'package:Biobase':
anyMissing, rowMedians
Attaching package: 'DelayedArray'
The following objects are masked from 'package:matrixStats':
colMaxs, colMins, colRanges, rowMaxs, rowMins, rowRanges
The following object is masked from 'package:Biostrings':
type
The following objects are masked from 'package:base':
aperm, apply
Loading required package: VariantAnnotation
Attaching package: 'VariantAnnotation'
The following object is masked from 'package:base':
tabulate
>
> source(getPackageFile("unitTests/runTests.R"))
Loading required package: GenomicFeatures
Loading required package: AnnotationDbi
did not source anything in dirname= ./R
Executing test function test.alignReads ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:46:25 INFO::preprocessReads.R/preprocessReads: starting...
2019-04-16 00:46:25 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:46:25 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2019-04-16 00:46:25 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:46:28 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:46:28 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/chunks/chunk_000001/logs/progress.log
2019-04-16 00:46:31 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.056 minutes
2019-04-16 00:46:31 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/chunks/chunk_000002/logs/progress.log
2019-04-16 00:46:34 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.054 minutes
2019-04-16 00:46:34 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/chunks/chunk_000003/logs/progress.log
2019-04-16 00:46:38 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.058 minutes
2019-04-16 00:46:38 DEBUG::tools.R/processChunks: done
2019-04-16 00:46:38 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:46:38 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/results/test_pe.adapter_contaminated_1.RData
2019-04-16 00:46:38 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2019-04-16 00:46:38 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/results/test_pe.adapter_contaminated_2.RData
2019-04-16 00:46:38 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2019-04-16 00:46:38 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/results/test_pe.summary_preprocess.tab
2019-04-16 00:46:38 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/bams/processed.aligner_input_1.fastq ...
2019-04-16 00:46:38 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/bams/processed.aligner_input_2.fastq ...
2019-04-16 00:46:38 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/reports/shortReadReport_1 ...
2019-04-16 00:46:41 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/reports/shortReadReport_2 ...
2019-04-16 00:46:43 INFO::preprocessReads.R/preprocessReads: done
2019-04-16 00:46:43 INFO::alignReads.R/alignReads: starting alignment...
2019-04-16 00:46:43 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:46:45 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:46:45 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/chunks/chunk_000001/logs/progress.log
2019-04-16 00:46:51 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.091 minutes
2019-04-16 00:46:51 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/chunks/chunk_000002/logs/progress.log
2019-04-16 00:46:54 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.052 minutes
2019-04-16 00:46:54 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/chunks/chunk_000003/logs/progress.log
2019-04-16 00:46:57 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.057 minutes
2019-04-16 00:46:57 DEBUG::tools.R/processChunks: done
2019-04-16 00:46:57 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2019-04-16 00:46:57 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2019-04-16 00:46:57 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/results/test_pe.summary_alignment.tab
2019-04-16 00:46:57 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/results/test_pe.summary_analyzed_bamstats.tab
2019-04-16 00:46:57 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2019-04-16 00:46:58 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.69d46605801/results/test_pe.summary_target_lengths.tab
2019-04-16 00:46:58 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2019-04-16 00:46:58 INFO::alignReads.R/alignReads: done
done successfully.
Executing test function test.alignReads.sparsechunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:46:59 INFO::preprocessReads.R/preprocessReads: starting...
2019-04-16 00:46:59 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:46:59 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2019-04-16 00:46:59 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:46:59 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2019-04-16 00:46:59 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:47:02 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:47:02 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/chunks/chunk_000001/logs/progress.log
2019-04-16 00:47:05 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2019-04-16 00:47:05 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/chunks/chunk_000002/logs/progress.log
2019-04-16 00:47:08 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.053 minutes
2019-04-16 00:47:08 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/chunks/chunk_000003/logs/progress.log
2019-04-16 00:47:11 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.052 minutes
2019-04-16 00:47:11 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/chunks/chunk_000004/logs/progress.log
2019-04-16 00:47:15 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.053 minutes
2019-04-16 00:47:15 DEBUG::tools.R/processChunks: done
2019-04-16 00:47:15 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:47:15 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/results/test_pe.adapter_contaminated_1.RData
2019-04-16 00:47:15 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2019-04-16 00:47:15 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/results/test_pe.adapter_contaminated_2.RData
2019-04-16 00:47:15 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2019-04-16 00:47:15 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/results/test_pe.summary_preprocess.tab
2019-04-16 00:47:15 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/bams/processed.aligner_input_1.fastq ...
2019-04-16 00:47:15 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/bams/processed.aligner_input_2.fastq ...
2019-04-16 00:47:15 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/reports/shortReadReport_1 ...
2019-04-16 00:47:17 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.alignReads.sparsechunks.69d5c84ed9a/reports/shortReadReport_2 ...
2019-04-16 00:47:19 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.alignReadsOneSingleEnd ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:47:20 INFO::alignReads.R/alignReadsChunk: running gsnap...
2019-04-16 00:47:20 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -D /home/biocbuild/.local/share/gmap -t 1 -d TP53_demo_3.2.2 --quality-protocol=illumina -A sam --read-group-id=test_se -m 0 --split-output /tmp/Rtmp4dQXq6/test.alignReadsOneSingleEnd.69d4d4b6c23/bams/test.alignReads /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2019-04-16 00:47:21 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2019-04-16 00:47:21 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReadsOneSingleEnd.69d4d4b6c23/results/test.alignReads.summary_alignment.tab
2019-04-16 00:47:21 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.alignReadsOneSingleEnd.69d4d4b6c23/results/test.alignReads.summary_analyzed_bamstats.tab
2019-04-16 00:47:21 INFO::alignReads.R/alignReadsChunk: done
done successfully.
Executing test function test.annotateVariants ... Timing stopped at: 0 0.044 0.049
Error in DEACTIVATED("Skipped annotateVariants() test") :
Skipped annotateVariants() test
In addition: Warning messages:
1: In system("gsnap", ignore.stderr = TRUE) : error in running command
2: In system("samtools", ignore.stderr = TRUE) : error in running command
3: In system("gsnap", ignore.stderr = TRUE) : error in running command
4: In system("samtools", ignore.stderr = TRUE) : error in running command
5: In system("gsnap", ignore.stderr = TRUE) : error in running command
6: In system("samtools", ignore.stderr = TRUE) : error in running command
7: In system2("variant_effect_predictor.pl", "--help", stderr = FALSE, :
error in running command
done successfully.
Executing test function test.callVariantsVariantTools.genotype ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:47:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.genotype.69d672ab8c9/results/test_pe.coverage.RData
2019-04-16 00:47:22 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4dQXq6/test.genotype.69d672ab8c9/results/test_pe.coverage.bw
2019-04-16 00:47:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.genotype.69d672ab8c9/results/test_pe.summary_coverage.tab
2019-04-16 00:47:22 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:47:26 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:47:26 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:47:26 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:47:26 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.genotype.69d672ab8c9/results/test_pe.raw_variants.RData
2019-04-16 00:47:26 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.genotype.69d672ab8c9/results/test_pe.filtered_variants.RData
2019-04-16 00:47:26 INFO::analyzeVariants.R/wrap.callVariants: ...done
2019-04-16 00:47:26 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2019-04-16 00:47:27 INFO::analyzeVariants.R/writeVCF: ...done
2019-04-16 00:47:27 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2019-04-16 00:48:37 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2019-04-16 00:48:38 INFO::analyzeVariants.R/writeVCF: ...done
2019-04-16 00:48:38 INFO::analyzeVariants.R/.callGenotypes: done
done successfully.
Executing test function test.wrap.callVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:48:39 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:48:41 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:48:41 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:48:41 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:48:41 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.69d1cab713b/results/test_pe.raw_variants.RData
2019-04-16 00:48:41 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.69d1cab713b/results/test_pe.filtered_variants.RData
2019-04-16 00:48:41 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.filters ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:48:43 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:48:48 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:48:48 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:48:48 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:48:48 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.filters.69d1ae9da6f/results/test_pe.raw_variants.RData
2019-04-16 00:48:48 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.filters.69d1ae9da6f/results/test_pe.filtered_variants.RData
2019-04-16 00:48:48 INFO::analyzeVariants.R/wrap.callVariants: ...done
2019-04-16 00:48:48 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:48:52 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:48:52 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:48:52 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:48:52 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.filters.69d1ae9da6f/results/test_pe.raw_variants.RData
2019-04-16 00:48:52 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.filters.69d1ae9da6f/results/test_pe.filtered_variants.RData
2019-04-16 00:48:52 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.parallel ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:48:54 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:48:58 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:48:58 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:48:58 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:48:58 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.parallel.69d1df7c472/results/test_pe.raw_variants.RData
2019-04-16 00:48:58 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.parallel.69d1df7c472/results/test_pe.filtered_variants.RData
2019-04-16 00:48:58 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.which ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:48:59 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:48:59 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2019-04-16 00:49:00 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:49:00 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:49:00 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:49:00 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.which.69dc059fc3/results/test_pe.raw_variants.RData
2019-04-16 00:49:00 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.wrap.callVariants.which.69dc059fc3/results/test_pe.filtered_variants.RData
2019-04-16 00:49:00 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.writeVCF.NULL ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:49:01 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2019-04-16 00:49:01 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.writeVCF.vcfStat ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:49:02 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2019-04-16 00:49:02 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.isFirstFragment ... done successfully.
Executing test function test.buildCountsGRangesList ... done successfully.
Executing test function test.generateSingleGeneDERs ... done successfully.
Executing test function test.computeCoverage ... done successfully.
Executing test function test.isSparse ... done successfully.
Executing test function test.mergeCoverage ... 2019-04-16 00:50:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/lisvempk/merged/results/bla.coverage.RData
2019-04-16 00:50:08 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4dQXq6/lisvempk/merged/results/bla.coverage.bw
2019-04-16 00:50:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/lisvempk/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.mergeCoverage.sparse ... 2019-04-16 00:50:09 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/qirdflou/merged/results/bla.coverage.RData
2019-04-16 00:50:09 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4dQXq6/qirdflou/merged/results/bla.coverage.bw
2019-04-16 00:50:09 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/qirdflou/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.checkConfig.analyzeVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.findTemplate ... done successfully.
Executing test function test.checkConfig ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.checkConfig.alignReads ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.getConfig ... done successfully.
Executing test function test.loadConfig ... done successfully.
Executing test function test.parseDCF ... done successfully.
Executing test function test.updateConfig ... done successfully.
Executing test function test.getAdapterSeqs ... done successfully.
Executing test function test.isAdapter ... done successfully.
Executing test function test.isAdapter3.primeEnd ... done successfully.
Executing test function test.detectRRNA ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:15 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2019-04-16 00:50:15 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4dQXq6/test.detectRRNA.69d29502d9e/bams/rRNA_contam/input1.fastq
2019-04-16 00:50:15 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp4dQXq6/test.detectRRNA.69d29502d9e/bams/rRNA_contam/test_se /tmp/Rtmp4dQXq6/test.detectRRNA.69d29502d9e/bams/rRNA_contam/input1.fastq 2>&1
2019-04-16 00:50:16 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2019-04-16 00:50:16 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.detectRRNA.paired_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:17 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2019-04-16 00:50:17 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4dQXq6/test.detectRRNA.paired_end.69d198a49f9/bams/rRNA_contam/input1.fastq
2019-04-16 00:50:17 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4dQXq6/test.detectRRNA.paired_end.69d198a49f9/bams/rRNA_contam/input2.fastq
2019-04-16 00:50:17 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp4dQXq6/test.detectRRNA.paired_end.69d198a49f9/bams/rRNA_contam/test_pe /tmp/Rtmp4dQXq6/test.detectRRNA.paired_end.69d198a49f9/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp4dQXq6/test.detectRRNA.paired_end.69d198a49f9/bams/rRNA_contam/input2.fastq 2>&1
2019-04-16 00:50:17 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2019-04-16 00:50:17 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.getRRNAIds ... 2019-04-16 00:50:17 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp4dQXq6/test_get_rRNA_idshcjvqyek/test_pe /tmp/Rtmp4dQXq6/test_get_rRNA_idshcjvqyek/1.fastq -a paired /tmp/Rtmp4dQXq6/test_get_rRNA_idshcjvqyek/2.fastq 2>&1
done successfully.
Executing test function test.getRRNAIds_random ... 2019-04-16 00:50:18 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp4dQXq6/test_get_rRNAIds_randomrndzkcyt/test_pe /tmp/Rtmp4dQXq6/test_get_rRNAIds_randomrndzkcyt/1.fastq 2>&1
done successfully.
Executing test function test.filterByLength ... 2019-04-16 00:50:18 INFO::filterQuality.R/filterQuality: filterByLength...
2019-04-16 00:50:18 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2019-04-16 00:50:18 INFO::filterQuality.R/filterByLength: done
2019-04-16 00:50:18 INFO::filterQuality.R/filterQuality: filterByLength...
2019-04-16 00:50:18 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2019-04-16 00:50:18 INFO::filterQuality.R/filterByLength: done
done successfully.
Executing test function test.isAboveQualityThresh ... done successfully.
Executing test function test.trimTailsByQuality ... 2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: done
2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: done
2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: done
2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2019-04-16 00:50:19 INFO::preprocessReads.R/preprocessReadsChunk: done
done successfully.
Executing test function test.callVariantsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
In addition: There were 27 warnings (use warnings() to see them)
done successfully.
Executing test function test.callVariantsGATK.withFiltering ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
done successfully.
Executing test function test.checkGATKJar ... Timing stopped at: 0 0 0.001
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") :
checkGATKJar() test needs gatk.path option set
done successfully.
Executing test function test.excludeVariantsByRegion ... done successfully.
Executing test function test.gatk ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") :
gatk() tests need gatk.path option set
done successfully.
Executing test function test.realignIndels ... Timing stopped at: 0 0 0
Error in DEACTIVATED("test.realignIndels() tests need gatk.path option set") :
test.realignIndels() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK.parallel ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test_zipUp ... done successfully.
Executing test function test.FastQStreamer.getReads.pefq ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:20 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:20 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
done successfully.
Executing test function test.FastQStreamer.getReads.pefq.subsample ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:21 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:21 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2019-04-16 00:50:21 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:21 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
done successfully.
Executing test function test.FastQStreamer.getReads.segz ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:23 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/reads.fastq.gz
done successfully.
Executing test function test.FastQStreamer.getReads.truncated ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:24 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/truncated.fastq.gz
done successfully.
Executing test function test.FastQStreamer.subsampler.isdeterministic ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:26 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:26 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2019-04-16 00:50:26 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:26 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:27 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:27 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2019-04-16 00:50:27 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:27 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
done successfully.
Executing test function test.createTmpDir ... done successfully.
Executing test function test.detectQualityInFASTQFile ... done successfully.
Executing test function test.getObjectFilename ... done successfully.
Executing test function test.safeUnlink ... done successfully.
Executing test function test.writeAudit ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.mergeLanes ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:50:31 INFO::preprocessReads.R/preprocessReads: starting...
2019-04-16 00:50:31 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:50:31 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2019-04-16 00:50:31 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:50:33 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:50:33 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000001/logs/progress.log
2019-04-16 00:50:36 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2019-04-16 00:50:36 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000002/logs/progress.log
2019-04-16 00:50:39 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2019-04-16 00:50:39 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000003/logs/progress.log
2019-04-16 00:50:42 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2019-04-16 00:50:42 DEBUG::tools.R/processChunks: done
2019-04-16 00:50:42 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:50:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.adapter_contaminated_1.RData
2019-04-16 00:50:42 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2019-04-16 00:50:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.adapter_contaminated_2.RData
2019-04-16 00:50:42 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2019-04-16 00:50:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.summary_preprocess.tab
2019-04-16 00:50:42 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/bams/processed.aligner_input_1.fastq ...
2019-04-16 00:50:42 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/bams/processed.aligner_input_2.fastq ...
2019-04-16 00:50:42 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/reports/shortReadReport_1 ...
2019-04-16 00:50:44 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/reports/shortReadReport_2 ...
2019-04-16 00:50:46 INFO::preprocessReads.R/preprocessReads: done
2019-04-16 00:50:47 INFO::alignReads.R/alignReads: starting alignment...
2019-04-16 00:50:47 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:50:49 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:50:49 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000001/logs/progress.log
2019-04-16 00:50:52 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2019-04-16 00:50:52 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000002/logs/progress.log
2019-04-16 00:50:54 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.048 minutes
2019-04-16 00:50:54 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000003/logs/progress.log
2019-04-16 00:50:57 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2019-04-16 00:50:57 DEBUG::tools.R/processChunks: done
2019-04-16 00:50:57 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2019-04-16 00:50:58 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2019-04-16 00:50:58 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.summary_alignment.tab
2019-04-16 00:50:58 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.summary_analyzed_bamstats.tab
2019-04-16 00:50:58 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2019-04-16 00:50:58 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.summary_target_lengths.tab
2019-04-16 00:50:58 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2019-04-16 00:50:58 INFO::alignReads.R/alignReads: done
2019-04-16 00:50:58 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2019-04-16 00:50:58 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:51:01 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:51:01 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000001/logs/progress.log
2019-04-16 00:51:03 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2019-04-16 00:51:03 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000002/logs/progress.log
2019-04-16 00:51:06 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2019-04-16 00:51:06 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000003/logs/progress.log
2019-04-16 00:51:08 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.04 minutes
2019-04-16 00:51:08 DEBUG::tools.R/processChunks: done
2019-04-16 00:51:08 INFO::countGenomicFeatures.R/mergeCounts: starting...
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.counts_exon.tab
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.counts_exon_disjoint.tab
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.counts_gene.tab
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.counts_gene_coding.tab
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.counts_gene_exonic.tab
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.counts_intergenic.tab
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.counts_intron.tab
2019-04-16 00:51:08 INFO::countGenomicFeatures.R/mergeCounts: done
2019-04-16 00:51:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.summary_counts.tab
2019-04-16 00:51:08 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2019-04-16 00:51:08 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2019-04-16 00:51:08 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2019-04-16 00:51:09 INFO::coverage.R/calculateCoverage: starting...
2019-04-16 00:51:09 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:51:11 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:51:11 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000001/logs/progress.log
2019-04-16 00:51:13 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2019-04-16 00:51:13 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000002/logs/progress.log
2019-04-16 00:51:15 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2019-04-16 00:51:15 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/chunks/chunk_000003/logs/progress.log
2019-04-16 00:51:18 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2019-04-16 00:51:18 DEBUG::tools.R/processChunks: done
2019-04-16 00:51:19 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.coverage.RData
2019-04-16 00:51:19 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.coverage.bw
2019-04-16 00:51:19 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.summary_coverage.tab
2019-04-16 00:51:19 INFO::coverage.R/calculateCoverage: done
2019-04-16 00:51:19 INFO::analyzeVariants/analyzeVariants: starting ...
2019-04-16 00:51:19 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:51:20 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:51:20 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:51:20 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:51:20 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.raw_variants.RData
2019-04-16 00:51:20 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.filtered_variants.RData
2019-04-16 00:51:20 INFO::analyzeVariants.R/wrap.callVariants: ...done
2019-04-16 00:51:21 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2019-04-16 00:51:21 INFO::analyzeVariants.R/writeVCF: ...done
2019-04-16 00:51:21 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/results/test_pe.summary_variants.tab
2019-04-16 00:51:21 INFO::analyzeVariants/analyzeVariants: done
2019-04-16 00:51:21 INFO::Pipeline run successful.
2019-04-16 00:51:22 INFO::mergeLanes.R/doMergeLanes: starting...
2019-04-16 00:51:22 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:51:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.adapter_contaminated_1.RData
2019-04-16 00:51:22 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2019-04-16 00:51:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.adapter_contaminated_2.RData
2019-04-16 00:51:22 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2019-04-16 00:51:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.summary_preprocess.tab
2019-04-16 00:51:22 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2019-04-16 00:51:22 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2019-04-16 00:51:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.summary_alignment.tab
2019-04-16 00:51:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.summary_analyzed_bamstats.tab
2019-04-16 00:51:22 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.summary_target_lengths.tab
2019-04-16 00:51:23 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2019-04-16 00:51:23 INFO::countGenomicFeatures.R/mergeCounts: starting...
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.counts_exon.tab
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.counts_exon_disjoint.tab
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.counts_gene.tab
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.counts_gene_coding.tab
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.counts_gene_exonic.tab
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.counts_intergenic.tab
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.counts_intron.tab
2019-04-16 00:51:23 INFO::countGenomicFeatures.R/mergeCounts: done
2019-04-16 00:51:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.summary_counts.tab
2019-04-16 00:51:23 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2019-04-16 00:51:23 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2019-04-16 00:51:25 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.coverage.RData
2019-04-16 00:51:25 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.coverage.bw
2019-04-16 00:51:25 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.summary_coverage.tab
2019-04-16 00:51:25 INFO::analyzeVariants/analyzeVariants: starting ...
2019-04-16 00:51:25 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:51:26 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:51:27 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:51:27 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:51:27 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.raw_variants.RData
2019-04-16 00:51:27 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.filtered_variants.RData
2019-04-16 00:51:27 INFO::analyzeVariants.R/wrap.callVariants: ...done
2019-04-16 00:51:27 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2019-04-16 00:51:27 INFO::analyzeVariants.R/writeVCF: ...done
2019-04-16 00:51:27 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.mergeLanes.69d1fcb646a/merged/results/merged.summary_variants.tab
2019-04-16 00:51:27 INFO::analyzeVariants/analyzeVariants: done
2019-04-16 00:51:27 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
done successfully.
Executing test function test.markDuplicates ... Timing stopped at: 0 0 0.001
Error in DEACTIVATED("Skipped markDuplicates() test") :
Skipped markDuplicates() test
In addition: There were 22 warnings (use warnings() to see them)
done successfully.
Executing test function test.markDuplicates_w_outfile ... Timing stopped at: 0 0 0
Error in DEACTIVATED("Skipped markDuplicates() test") :
Skipped markDuplicates() test
done successfully.
Executing test function test.preprocessReads ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:51:28 INFO::preprocessReads.R/preprocessReads: starting...
2019-04-16 00:51:28 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:51:28 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2019-04-16 00:51:28 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:51:31 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:51:31 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/chunks/chunk_000001/logs/progress.log
2019-04-16 00:51:34 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2019-04-16 00:51:34 DEBUG::tools.R/processChunks: done
2019-04-16 00:51:34 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:51:34 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/results/test_pe.adapter_contaminated_1.RData
2019-04-16 00:51:34 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2019-04-16 00:51:34 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/results/test_pe.adapter_contaminated_2.RData
2019-04-16 00:51:34 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2019-04-16 00:51:34 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/results/test_pe.summary_preprocess.tab
2019-04-16 00:51:34 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/bams/processed.aligner_input_1.fastq ...
2019-04-16 00:51:34 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/bams/processed.aligner_input_2.fastq ...
2019-04-16 00:51:34 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/reports/shortReadReport_1 ...
2019-04-16 00:51:36 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.preprocessReads.69d2ab53ed5/reports/shortReadReport_2 ...
2019-04-16 00:51:37 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads.minichunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:51:38 INFO::preprocessReads.R/preprocessReads: starting...
2019-04-16 00:51:38 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:51:38 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2019-04-16 00:51:38 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:51:41 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:51:41 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/chunks/chunk_000001/logs/progress.log
2019-04-16 00:51:44 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2019-04-16 00:51:44 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/chunks/chunk_000002/logs/progress.log
2019-04-16 00:51:47 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.049 minutes
2019-04-16 00:51:47 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/chunks/chunk_000003/logs/progress.log
2019-04-16 00:51:50 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2019-04-16 00:51:50 DEBUG::tools.R/processChunks: done
2019-04-16 00:51:50 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:51:50 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/results/test_pe.adapter_contaminated_1.RData
2019-04-16 00:51:50 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2019-04-16 00:51:50 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/results/test_pe.adapter_contaminated_2.RData
2019-04-16 00:51:50 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2019-04-16 00:51:50 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/results/test_pe.summary_preprocess.tab
2019-04-16 00:51:50 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/bams/processed.aligner_input_1.fastq ...
2019-04-16 00:51:50 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/bams/processed.aligner_input_2.fastq ...
2019-04-16 00:51:50 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/reports/shortReadReport_1 ...
2019-04-16 00:51:52 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.preprocessReads.minichunks.69d756d3192/reports/shortReadReport_2 ...
2019-04-16 00:51:54 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads_single_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:51:55 INFO::preprocessReads.R/preprocessReads: starting...
2019-04-16 00:51:55 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2019-04-16 00:51:55 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:51:58 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:51:58 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4dQXq6/test.preprocessReads_single_end.69d20f6c2c0/chunks/chunk_000001/logs/progress.log
2019-04-16 00:52:00 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2019-04-16 00:52:00 DEBUG::tools.R/processChunks: done
2019-04-16 00:52:00 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:52:00 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads_single_end.69d20f6c2c0/results/test_se.adapter_contaminated_1.RData
2019-04-16 00:52:00 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2019-04-16 00:52:00 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.preprocessReads_single_end.69d20f6c2c0/results/test_se.summary_preprocess.tab
2019-04-16 00:52:00 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4dQXq6/test.preprocessReads_single_end.69d20f6c2c0/bams/processed.aligner_input_1.fastq ...
2019-04-16 00:52:00 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4dQXq6/test.preprocessReads_single_end.69d20f6c2c0/reports/shortReadReport_1 ...
2019-04-16 00:52:02 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.readRNASeqEnds ... done successfully.
Executing test function test.readRNASeqEnds.dupmark ... done successfully.
Executing test function test.how_many ... done successfully.
Executing test function test.plotDF ... done successfully.
Executing test function test.relativeBarPlot ... done successfully.
Executing test function test.runPipeline ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:52:04 INFO::preprocessReads.R/preprocessReads: starting...
2019-04-16 00:52:04 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2019-04-16 00:52:04 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2019-04-16 00:52:04 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:52:06 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:52:06 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2019-04-16 00:52:09 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2019-04-16 00:52:09 DEBUG::tools.R/processChunks: done
2019-04-16 00:52:09 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2019-04-16 00:52:09 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2019-04-16 00:52:09 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2019-04-16 00:52:09 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2019-04-16 00:52:09 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2500 highqual_reads=2500 adapter_contam=0 read_length=100 rRNA_contam_reads=0 processed_reads=2500 input_min_read_length=100 input_max_read_length=100 processed_min_read_length=71 processed_max_read_length=100
2019-04-16 00:52:09 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2019-04-16 00:52:09 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2019-04-16 00:52:09 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2019-04-16 00:52:09 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2019-04-16 00:52:12 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2019-04-16 00:52:14 INFO::preprocessReads.R/preprocessReads: done
2019-04-16 00:52:14 INFO::alignReads.R/alignReads: starting alignment...
2019-04-16 00:52:14 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:52:17 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:52:17 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2019-04-16 00:52:22 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.09 minutes
2019-04-16 00:52:22 DEBUG::tools.R/processChunks: done
2019-04-16 00:52:22 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2019-04-16 00:52:22 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2019-04-16 00:52:22 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2019-04-16 00:52:22 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2019-04-16 00:52:22 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2019-04-16 00:52:22 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2019-04-16 00:52:22 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2019-04-16 00:52:22 INFO::alignReads.R/alignReads: done
2019-04-16 00:52:23 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2019-04-16 00:52:23 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:52:25 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:52:25 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2019-04-16 00:52:28 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2019-04-16 00:52:28 DEBUG::tools.R/processChunks: done
2019-04-16 00:52:28 INFO::countGenomicFeatures.R/mergeCounts: starting...
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2019-04-16 00:52:28 INFO::countGenomicFeatures.R/mergeCounts: done
2019-04-16 00:52:28 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2019-04-16 00:52:28 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2019-04-16 00:52:28 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2019-04-16 00:52:28 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2019-04-16 00:52:28 INFO::coverage.R/calculateCoverage: starting...
2019-04-16 00:52:28 DEBUG::tools.R/processChunks: starting...
2019-04-16 00:52:31 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2019-04-16 00:52:31 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2019-04-16 00:52:33 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2019-04-16 00:52:33 DEBUG::tools.R/processChunks: done
2019-04-16 00:52:34 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2019-04-16 00:52:34 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2019-04-16 00:52:34 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2019-04-16 00:52:34 INFO::coverage.R/calculateCoverage: done
2019-04-16 00:52:34 INFO::analyzeVariants/analyzeVariants: starting ...
2019-04-16 00:52:34 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2019-04-16 00:52:39 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2019-04-16 00:52:39 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2019-04-16 00:52:39 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2019-04-16 00:52:39 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2019-04-16 00:52:39 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2019-04-16 00:52:39 INFO::analyzeVariants.R/wrap.callVariants: ...done
2019-04-16 00:52:39 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2019-04-16 00:52:39 INFO::analyzeVariants.R/writeVCF: ...done
2019-04-16 00:52:40 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2019-04-16 00:52:40 INFO::analyzeVariants/analyzeVariants: done
2019-04-16 00:52:40 INFO::Pipeline run successful.
done successfully.
Executing test function test.calculateTargetLength ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4dQXq6/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/config/default-config.txt
2019-04-16 00:52:41 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4dQXq6/test.calcTargetLengths.69d7163ca24/results/test_pe.summary_target_lengths.tab
done successfully.
Executing test function test.sclapply ... done successfully.
Executing test function test.tryKeepTraceback ... done successfully.
Executing test function test.truncateReads ... done successfully.
Executing test function test.truncateReads.trim5 ... done successfully.
RUNIT TEST PROTOCOL -- Tue Apr 16 00:52:58 2019
***********************************************
Number of test functions: 62
Number of deactivated test functions: 10
Number of errors: 0
Number of failures: 0
1 Test Suite :
HTSeqGenie unit testing - 62 test functions, 0 errors, 0 failures
Details
***************************
Test Suite: HTSeqGenie unit testing
Test function regexp: ^test.+
Test file regexp: ^runit.+\.[rR]$
Involved directory:
/home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.alignReads.R
test.alignReads: (2 checks) ... OK (35.09 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (21.31 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (1.39 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.analyzeVariants.R
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (76.98 seconds)
test.wrap.callVariants: (4 checks) ... OK (3.42 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (11.25 seconds)
test.wrap.callVariants.parallel: (1 checks) ... OK (5.12 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.43 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.87 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (1.36 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.bamUtils.R
test.isFirstFragment: (5 checks) ... OK (0 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R
test.buildCountsGRangesList: (3 checks) ... OK (35.42 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (28.08 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.calculateCoverage.R
test.computeCoverage: (9 checks) ... OK (0.77 seconds)
test.isSparse: (5 checks) ... OK (0.08 seconds)
test.mergeCoverage: (1 checks) ... OK (1.2 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.02 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.checkConfig.R
test.checkConfig.analyzeVariants: (5 checks) ... OK (1 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.config.R
test.checkConfig: (5 checks) ... OK (1.62 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (2.26 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.detectAdapterContam.R
test.getAdapterSeqs: (5 checks) ... OK (0.09 seconds)
test.isAdapter: (5 checks) ... OK (0.22 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.14 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.detectRRNA.R
test.detectRRNA: (1 checks) ... OK (1.44 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (1.67 seconds)
test.getRRNAIds: (1 checks) ... OK (0.58 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.41 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.filterQuality.R
test.filterByLength: (2 checks) ... OK (0.08 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.06 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.05 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.gatk.R
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.16 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0.1 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.io.R
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.98 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (2.57 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (1.02 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (1.07 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (2.14 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.11 seconds)
test.getObjectFilename: (4 checks) ... OK (0.08 seconds)
test.safeUnlink: (2 checks) ... OK (0.23 seconds)
test.writeAudit: (0 checks) ... OK (1.57 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.mergeLanes.R
test.mergeLanes: (6 checks) ... OK (58.6 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.picard.R
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.preprocessReads.R
test.preprocessReads: (5 checks) ... OK (9.9 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (16.97 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.16 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R
test.readRNASeqEnds: (6 checks) ... OK (0.12 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.09 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.reportPipelineQA.R
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.16 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.04 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.runPipeline.R
test.runPipeline: (1 checks) ... OK (36.88 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.targetLengths.R
test.calculateTargetLength: (4 checks) ... OK (1.2 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.tools.R
test.sclapply: (10 checks) ... OK (16.58 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.8-bioc/R/library/HTSeqGenie/unitTests/runit.trimReads.R
test.truncateReads: (7 checks) ... OK (0.05 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.16 seconds)
runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
>
> proc.time()
user system elapsed
249.016 93.080 412.842