Back to the "Multiple platform build/check report" A  B  C  D  E  F  G [H] I  J  K  L  M  N  O  P  Q  R  S  T  U  V  W  X  Y  Z 

BioC 3.4: CHECK report for HTSeqGenie on zin1

This page was generated on 2016-09-21 03:38:02 -0700 (Wed, 21 Sep 2016).

Package 585/1257HostnameOS / ArchINSTALLBUILDCHECKBUILD BIN
HTSeqGenie 4.3.0
Jens Reeder
Snapshot Date: 2016-09-19 19:15:14 -0700 (Mon, 19 Sep 2016)
URL: https://hedgehog.fhcrc.org/bioconductor/trunk/madman/Rpacks/HTSeqGenie
Last Changed Rev: 117081 / Revision: 121152
Last Changed Date: 2016-05-03 14:30:44 -0700 (Tue, 03 May 2016)
zin1 Linux (Ubuntu 16.04 LTS) / x86_64  NotNeeded  OK [ ERROR ]
moscato1 Windows Server 2008 R2 Standard (64-bit) / x64 ...NOT SUPPORTED...NOT SUPPORTED...NOT SUPPORTED...
morelia Mac OS X Mavericks (10.9.5) / x86_64 ...NOT SUPPORTED...NOT SUPPORTED...NOT SUPPORTED...

Summary

Package: HTSeqGenie
Version: 4.3.0
Command: /home/biocbuild/bbs-3.4-bioc/R/bin/R CMD check --no-vignettes --timings HTSeqGenie_4.3.0.tar.gz
StartedAt: 2016-09-20 07:55:45 -0700 (Tue, 20 Sep 2016)
EndedAt: 2016-09-20 08:19:57 -0700 (Tue, 20 Sep 2016)
EllapsedTime: 1452.4 seconds
RetCode: 1
Status:  ERROR 
CheckDir: HTSeqGenie.Rcheck
Warnings: NA

Command output

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/bbs-3.4-bioc/R/bin/R CMD check --no-vignettes --timings HTSeqGenie_4.3.0.tar.gz
###
##############################################################################
##############################################################################


* using log directory ‘/home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck’
* using R version 3.3.1 (2016-06-21)
* using platform: x86_64-pc-linux-gnu (64-bit)
* using session charset: UTF-8
* using option ‘--no-vignettes’
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.3.0’
* checking package namespace information ... OK
* checking package dependencies ... OK
* checking if this is a source package ... OK
* checking if there is a namespace ... OK
* checking for hidden files and directories ... NOTE
Found the following hidden files and directories:
  .BBSoptions
These were most likely included in error. See section ‘Package
structure’ in the ‘Writing R Extensions’ manual.
* checking for portable file names ... OK
* checking for sufficient/correct file permissions ... OK
* checking whether package ‘HTSeqGenie’ can be installed ... OK
* checking installed package size ... NOTE
  installed size is  5.0Mb
  sub-directories of 1Mb or more:
    test-data   3.6Mb
* checking package directory ... OK
* checking ‘build’ directory ... OK
* checking DESCRIPTION meta-information ... NOTE
Malformed Title field: should not end in a period.
* checking top-level files ... OK
* checking for left-over files ... OK
* checking index information ... OK
* checking package subdirectories ... OK
* checking R files for non-ASCII characters ... OK
* checking R files for syntax errors ... OK
* checking whether the package can be loaded ... OK
* checking whether the package can be loaded with stated dependencies ... OK
* checking whether the package can be unloaded cleanly ... OK
* checking whether the namespace can be loaded with stated dependencies ... OK
* checking whether the namespace can be unloaded cleanly ... OK
* checking loading without being on the library search path ... OK
* checking dependencies in R code ... NOTE
Unexported objects imported by ':::' calls:
  ‘ShortRead:::.set_omp_threads’ ‘gmapR:::..gsnap’ ‘gmapR:::GeneGenome’
  ‘gmapR:::checkPackageInstalled’ ‘gmapR:::getDefaultGmapGenomePath’
  ‘gmapR:::getGeneRoi’ ‘gmapR:::subsetRegion’ ‘parallel:::mckill’
  See the note in ?`:::` about the use of this operator.
* checking S3 generic/method consistency ... OK
* checking replacement functions ... OK
* checking foreign function calls ... NOTE
Foreign function call to a different package:
  .Call(ShortRead:::.set_omp_threads, ...)
See chapter ‘System and foreign language interfaces’ in the ‘Writing R
Extensions’ manual.
* checking R code for possible problems ... NOTE
.makePreprocessAlignPlots: no visible binding for global variable
  ‘data’
.plot.in.out.min.max.readlength: no visible global function definition
  for ‘median’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.lfqs’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.chunkid’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.subsampling_filter’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.max_nbchunks’
addHandler: no visible binding for '<<-' assignment to
  ‘logging.handlers’
addHandler: no visible binding for global variable ‘logging.handlers’
addHandler: no visible binding for '<<-' assignment to ‘logging.file’
buildAnyFastaGenome: no visible global function definition for ‘getSeq’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘gaps’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘ranges’
buildTP53FastaGenome: no visible global function definition for
  ‘getSeq’
buildTP53GenomeTemplate: no visible global function definition for
  ‘path’
buildTallyParam: no visible global function definition for ‘seqinfo’
computeCoverage: no visible global function definition for ‘resize’
computeCoverage: no visible global function definition for ‘coverage’
estimateCutoffs : <anonymous>: no visible binding for global variable
  ‘quantile’
getGenomeSegments: no visible global function definition for ‘seqinfo’
hashVariants: no visible global function definition for ‘ranges’
isAboveQualityThresh: no visible global function definition for ‘Views’
isAboveQualityThresh: no visible global function definition for
  ‘viewMeans’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.n’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.x’
logReset: no visible binding for '<<-' assignment to ‘logging.handlers’
logReset: no visible binding for '<<-' assignment to ‘logging.loglevel’
logReset: no visible binding for '<<-' assignment to ‘logging.file’
loglevel: no visible binding for global variable ‘logging.loglevel’
loglevel: no visible binding for global variable ‘logging.handlers’
plotDF : .plot: no visible global function definition for ‘plot’
processChunks : tracefun: no visible binding for global variable
  ‘sjobs’
processChunks : tracefun: no visible binding for global variable
  ‘chunkid’
setLevel: no visible binding for '<<-' assignment to ‘logging.loglevel’
statCountFeatures: no visible global function definition for ‘quantile’
truncateReads: no visible global function definition for ‘subseq’
vcfStat: no visible global function definition for ‘quantile’
writeToFile: no visible binding for global variable ‘logging.file’
Undefined global functions or variables:
  Views chunkid coverage data gaps getSeq logging.file logging.handlers
  logging.loglevel median path plot quantile ranges resize seqinfo
  sjobs subseq viewMeans
Consider adding
  importFrom("graphics", "plot")
  importFrom("stats", "median", "quantile")
  importFrom("utils", "data")
to your NAMESPACE file.
* checking Rd files ... OK
* checking Rd metadata ... OK
* checking Rd cross-references ... OK
* checking for missing documentation entries ... WARNING
Undocumented code objects:
  ‘annotateVariants’
All user-level objects in a package should have documentation entries.
See chapter ‘Writing R documentation files’ in the ‘Writing R
Extensions’ manual.
* checking for code/documentation mismatches ... OK
* checking Rd \usage sections ... OK
* checking Rd contents ... OK
* checking for unstated dependencies in examples ... OK
* checking sizes of PDF files under ‘inst/doc’ ... OK
* checking installed files from ‘inst/doc’ ... OK
* checking files in ‘vignettes’ ... OK
* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
  Running ‘doRUnit.R’
 ERROR
Running the tests in ‘tests/doRUnit.R’ failed.
Last 13 lines of output:
  test.sclapply: ERROR !! 
  Error in mcfork(detached) : 
    unable to fork, possible reason: Cannot allocate memory
  test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
  --------------------------- 
  Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.trimReads.R 
  test.truncateReads: (7 checks) ... OK (0.03 seconds)
  test.truncateReads.trim5: (15 checks) ... OK (0.1 seconds) 
  
  Error in eval(expr, envir, enclos) : 
    runTests.R: failed to run unit tests, see /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/tests/HTSeqGenie-runit.txt for details
  Calls: source -> withVisible -> eval -> eval
  Execution halted
* checking for unstated dependencies in vignettes ... OK
* checking package vignettes in ‘inst/doc’ ... OK
* checking running R code from vignettes ... SKIPPED
* checking re-building of vignette outputs ... SKIPPED
* checking PDF version of manual ... OK
* DONE

Status: 1 ERROR, 1 WARNING, 6 NOTEs
See
  ‘/home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/00check.log’
for details.

doRUnit.Rout.fail:


R version 3.3.1 (2016-06-21) -- "Bug in Your Hair"
Copyright (C) 2016 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, xtabs

The following objects are masked from 'package:base':

    Filter, Find, Map, Position, Reduce, anyDuplicated, append,
    as.data.frame, cbind, colnames, 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, 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 objects are masked from 'package:base':

    colMeans, colSums, expand.grid, rowMeans, rowSums

Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector
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: 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/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 07:59:20 INFO::preprocessReads.R/preprocessReads: starting...
2016-09-20 07:59:20 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 07:59:20 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_2.fastq
2016-09-20 07:59:20 DEBUG::tools.R/processChunks: starting...
2016-09-20 07:59:21 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 07:59:21 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/chunks/chunk_000001/logs/progress.log
2016-09-20 07:59:23 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2016-09-20 07:59:23 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/chunks/chunk_000002/logs/progress.log
2016-09-20 07:59:26 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2016-09-20 07:59:26 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/chunks/chunk_000003/logs/progress.log
2016-09-20 07:59:29 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2016-09-20 07:59:29 DEBUG::tools.R/processChunks: done
2016-09-20 07:59:29 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 07:59:29 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/results/test_pe.adapter_contaminated_1.RData
2016-09-20 07:59:29 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2016-09-20 07:59:29 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/results/test_pe.adapter_contaminated_2.RData
2016-09-20 07:59:29 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
2016-09-20 07:59:29 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/results/test_pe.summary_preprocess.tab
2016-09-20 07:59:29 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/bams/processed.aligner_input_1.fastq ...
2016-09-20 07:59:29 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/bams/processed.aligner_input_2.fastq ...
2016-09-20 07:59:29 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/reports/shortReadReport_1 ...
2016-09-20 07:59:30 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/reports/shortReadReport_2 ...
2016-09-20 07:59:32 INFO::preprocessReads.R/preprocessReads: done
2016-09-20 07:59:32 INFO::alignReads.R/alignReads: starting alignment...
2016-09-20 07:59:32 DEBUG::tools.R/processChunks: starting...
2016-09-20 07:59:33 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 07:59:33 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/chunks/chunk_000001/logs/progress.log
2016-09-20 07:59:37 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.067 minutes
2016-09-20 07:59:37 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/chunks/chunk_000002/logs/progress.log
2016-09-20 07:59:39 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2016-09-20 07:59:39 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/chunks/chunk_000003/logs/progress.log
2016-09-20 07:59:42 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2016-09-20 07:59:42 DEBUG::tools.R/processChunks: done
2016-09-20 07:59:42 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2016-09-20 07:59:42 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2016-09-20 07:59:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/results/test_pe.summary_alignment.tab
2016-09-20 07:59:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/results/test_pe.summary_analyzed_bamstats.tab
2016-09-20 07:59:42 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2016-09-20 07:59:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.79f5263be62b/results/test_pe.summary_target_lengths.tab
2016-09-20 07:59:43 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2016-09-20 07:59:43 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 07:59:44 INFO::preprocessReads.R/preprocessReads: starting...
2016-09-20 07:59:44 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 07:59:44 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2016-09-20 07:59:44 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 07:59:44 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_2.fastq
2016-09-20 07:59:44 DEBUG::tools.R/processChunks: starting...
2016-09-20 07:59:45 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 07:59:45 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/chunks/chunk_000001/logs/progress.log
2016-09-20 07:59:48 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2016-09-20 07:59:48 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/chunks/chunk_000002/logs/progress.log
2016-09-20 07:59:50 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2016-09-20 07:59:50 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/chunks/chunk_000003/logs/progress.log
2016-09-20 07:59:53 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2016-09-20 07:59:53 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/chunks/chunk_000004/logs/progress.log
2016-09-20 07:59:56 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.042 minutes
2016-09-20 07:59:56 DEBUG::tools.R/processChunks: done
2016-09-20 07:59:56 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 07:59:56 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/results/test_pe.adapter_contaminated_1.RData
2016-09-20 07:59:56 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2016-09-20 07:59:56 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/results/test_pe.adapter_contaminated_2.RData
2016-09-20 07:59:56 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
2016-09-20 07:59:56 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/results/test_pe.summary_preprocess.tab
2016-09-20 07:59:56 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/bams/processed.aligner_input_1.fastq ...
2016-09-20 07:59:56 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/bams/processed.aligner_input_2.fastq ...
2016-09-20 07:59:56 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/reports/shortReadReport_1 ...
2016-09-20 07:59:57 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.alignReads.sparsechunks.79f562faf7ab/reports/shortReadReport_2 ...
2016-09-20 07:59:58 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:00 INFO::alignReads.R/alignReadsChunk: running gsnap...
2016-09-20 08:00:00 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/Rtmp8SYYBa/test.alignReadsOneSingleEnd.79f57eed7cc5/bams/test.alignReads /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2016-09-20 08:00:00 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2016-09-20 08:00:00 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReadsOneSingleEnd.79f57eed7cc5/results/test.alignReads.summary_alignment.tab
2016-09-20 08:00:00 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.alignReadsOneSingleEnd.79f57eed7cc5/results/test.alignReads.summary_analyzed_bamstats.tab
2016-09-20 08:00:00 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:02 INFO::analyzeVariants/annotateVariants: starting...
Timing stopped at: 1.836 0.316 7.996 
Error in annotateVariants(vcf) : 
  variant_effect_predictor.pl failed.--vcf --sift b --polyphen b --protein --check_existing --check_alleles --symbol --canonical --ccds --maf_1kg --maf_esp --cache --force_overwrite --no_stats --fork 2 --input_file /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/braf_v600.vcf --output_file /tmp/Rtmp8SYYBa/test.annotateVariants.79f52a878016/results/test_pe.variants_vep.vcf
 done successfully.



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:10 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.genotype.79f53df5557b/results/test_pe.coverage.RData
2016-09-20 08:00:10 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp8SYYBa/test.genotype.79f53df5557b/results/test_pe.coverage.bw
2016-09-20 08:00:10 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.genotype.79f53df5557b/results/test_pe.summary_coverage.tab
2016-09-20 08:00:10 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:00:11 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:00:11 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:00:11 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:00:11 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.genotype.79f53df5557b/results/test_pe.raw_variants.RData
2016-09-20 08:00:11 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.genotype.79f53df5557b/results/test_pe.filtered_variants.RData
2016-09-20 08:00:11 INFO::analyzeVariants.R/wrap.callVariants: ...done
2016-09-20 08:00:11 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2016-09-20 08:00:11 INFO::analyzeVariants.R/writeVCF: ...done
2016-09-20 08:00:11 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2016-09-20 08:00:37 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2016-09-20 08:00:37 INFO::analyzeVariants.R/writeVCF: ...done
2016-09-20 08:00:37 INFO::analyzeVariants.R/.callGenotypes: done
 done successfully.



Executing test function test.wrap.callVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:39 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:00:40 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:00:40 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:00:40 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:00:40 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.79f516cec76b/results/test_pe.raw_variants.RData
2016-09-20 08:00:40 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.79f516cec76b/results/test_pe.filtered_variants.RData
2016-09-20 08:00:40 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:41 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:00:42 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:00:42 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:00:42 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:00:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.filters.79f519f2eb1c/results/test_pe.raw_variants.RData
2016-09-20 08:00:42 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.filters.79f519f2eb1c/results/test_pe.filtered_variants.RData
2016-09-20 08:00:42 INFO::analyzeVariants.R/wrap.callVariants: ...done
2016-09-20 08:00:42 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:00:43 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:00:43 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:00:43 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:00:43 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.filters.79f519f2eb1c/results/test_pe.raw_variants.RData
2016-09-20 08:00:43 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.filters.79f519f2eb1c/results/test_pe.filtered_variants.RData
2016-09-20 08:00:43 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.parallel  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:45 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:00:48 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:00:49 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:00:49 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:00:49 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.parallel.79f5156e421f/results/test_pe.raw_variants.RData
2016-09-20 08:00:49 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.parallel.79f5156e421f/results/test_pe.filtered_variants.RData
2016-09-20 08:00:49 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:50 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:00:50 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2016-09-20 08:00:50 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:00:50 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:00:51 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:00:51 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.which.79f5113d2913/results/test_pe.raw_variants.RData
2016-09-20 08:00:51 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.wrap.callVariants.which.79f5113d2913/results/test_pe.filtered_variants.RData
2016-09-20 08:00:51 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:52 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2016-09-20 08:00:52 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:00:53 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2016-09-20 08:00:53 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  ... 2016-09-20 08:16:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/vbkpxlgw/merged/results/bla.coverage.RData
2016-09-20 08:16:22 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp8SYYBa/vbkpxlgw/merged/results/bla.coverage.bw
2016-09-20 08:16:23 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/vbkpxlgw/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2016-09-20 08:16:24 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/gjdybclw/merged/results/bla.coverage.RData
2016-09-20 08:16:24 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp8SYYBa/gjdybclw/merged/results/bla.coverage.bw
2016-09-20 08:16:24 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/gjdybclw/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/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/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/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/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:16:40 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2016-09-20 08:16:40 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp8SYYBa/test.detectRRNA.79f51f2d41ce/bams/rRNA_contam/input1.fastq
2016-09-20 08:16:40 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/Rtmp8SYYBa/test.detectRRNA.79f51f2d41ce/bams/rRNA_contam/test_se /tmp/Rtmp8SYYBa/test.detectRRNA.79f51f2d41ce/bams/rRNA_contam/input1.fastq 2>&1
2016-09-20 08:16:40 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2016-09-20 08:16:40 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:16:43 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2016-09-20 08:16:43 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp8SYYBa/test.detectRRNA.paired_end.79f57f8b0362/bams/rRNA_contam/input1.fastq
2016-09-20 08:16:43 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp8SYYBa/test.detectRRNA.paired_end.79f57f8b0362/bams/rRNA_contam/input2.fastq
2016-09-20 08:16:43 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/Rtmp8SYYBa/test.detectRRNA.paired_end.79f57f8b0362/bams/rRNA_contam/test_pe /tmp/Rtmp8SYYBa/test.detectRRNA.paired_end.79f57f8b0362/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp8SYYBa/test.detectRRNA.paired_end.79f57f8b0362/bams/rRNA_contam/input2.fastq 2>&1
2016-09-20 08:16:44 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2016-09-20 08:16:44 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2016-09-20 08:16:44 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/Rtmp8SYYBa/test_get_rRNA_idsmixclfrh/test_pe /tmp/Rtmp8SYYBa/test_get_rRNA_idsmixclfrh/1.fastq -a paired /tmp/Rtmp8SYYBa/test_get_rRNA_idsmixclfrh/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2016-09-20 08:16:45 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/Rtmp8SYYBa/test_get_rRNAIds_randomnapmwesh/test_pe /tmp/Rtmp8SYYBa/test_get_rRNAIds_randomnapmwesh/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2016-09-20 08:16:47 INFO::filterQuality.R/filterQuality: filterByLength...
2016-09-20 08:16:47 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2016-09-20 08:16:47 INFO::filterQuality.R/filterByLength: done
2016-09-20 08:16:47 INFO::filterQuality.R/filterQuality: filterByLength...
2016-09-20 08:16:47 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2016-09-20 08:16:47 INFO::filterQuality.R/filterByLength: done
 done successfully.



Executing test function test.isAboveQualityThresh  ...  done successfully.



Executing test function test.trimTailsByQuality  ... 2016-09-20 08:16:48 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2016-09-20 08:16:48 INFO::preprocessReads.R/preprocessReadsChunk: done
2016-09-20 08:16:48 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2016-09-20 08:16:48 INFO::preprocessReads.R/preprocessReadsChunk: done
2016-09-20 08:16:48 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2016-09-20 08:16:48 INFO::preprocessReads.R/preprocessReadsChunk: done
2016-09-20 08:16:48 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2016-09-20 08:16:48 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: Warning message:
closing unused connection 3 (/tmp/Rtmp8SYYBa/template_test_config.txt) 
 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 
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.004 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/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:16:55 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:16:55 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/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/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:16:57 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:16:57 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2016-09-20 08:16:57 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:16:57 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:17:00 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:17:02 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:17:05 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:17:05 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2016-09-20 08:17:05 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:17:05 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:17:07 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:17:07 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2016-09-20 08:17:07 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:17:07 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/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/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:17:18 INFO::preprocessReads.R/preprocessReads: starting...
2016-09-20 08:17:18 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:17:18 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_2.fastq
2016-09-20 08:17:18 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:17:20 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:17:20 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000001/logs/progress.log
2016-09-20 08:17:22 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2016-09-20 08:17:22 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000002/logs/progress.log
2016-09-20 08:17:25 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2016-09-20 08:17:25 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000003/logs/progress.log
2016-09-20 08:17:28 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2016-09-20 08:17:28 DEBUG::tools.R/processChunks: done
2016-09-20 08:17:28 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 08:17:28 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.adapter_contaminated_1.RData
2016-09-20 08:17:28 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2016-09-20 08:17:28 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.adapter_contaminated_2.RData
2016-09-20 08:17:28 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
2016-09-20 08:17:28 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.summary_preprocess.tab
2016-09-20 08:17:28 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/bams/processed.aligner_input_1.fastq ...
2016-09-20 08:17:28 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/bams/processed.aligner_input_2.fastq ...
2016-09-20 08:17:28 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/reports/shortReadReport_1 ...
2016-09-20 08:17:30 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/reports/shortReadReport_2 ...
2016-09-20 08:17:32 INFO::preprocessReads.R/preprocessReads: done
2016-09-20 08:17:33 INFO::alignReads.R/alignReads: starting alignment...
2016-09-20 08:17:33 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:17:34 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:17:34 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000001/logs/progress.log
2016-09-20 08:17:37 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2016-09-20 08:17:37 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000002/logs/progress.log
2016-09-20 08:17:40 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.051 minutes
2016-09-20 08:17:40 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000003/logs/progress.log
2016-09-20 08:17:43 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.051 minutes
2016-09-20 08:17:43 DEBUG::tools.R/processChunks: done
2016-09-20 08:17:43 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2016-09-20 08:17:43 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2016-09-20 08:17:43 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.summary_alignment.tab
2016-09-20 08:17:43 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.summary_analyzed_bamstats.tab
2016-09-20 08:17:43 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2016-09-20 08:17:44 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.summary_target_lengths.tab
2016-09-20 08:17:44 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2016-09-20 08:17:44 INFO::alignReads.R/alignReads: done
2016-09-20 08:17:44 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2016-09-20 08:17:44 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:17:45 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:17:45 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000001/logs/progress.log
2016-09-20 08:17:48 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2016-09-20 08:17:48 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000002/logs/progress.log
2016-09-20 08:17:50 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2016-09-20 08:17:50 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000003/logs/progress.log
2016-09-20 08:17:53 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2016-09-20 08:17:53 DEBUG::tools.R/processChunks: done
2016-09-20 08:17:53 INFO::countGenomicFeatures.R/mergeCounts: starting...
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.counts_exon.tab
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.counts_gene.tab
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.counts_gene_coding.tab
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.counts_gene_exonic.tab
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.counts_intergenic.tab
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.counts_intron.tab
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.counts_transcript.tab
2016-09-20 08:17:53 INFO::countGenomicFeatures.R/mergeCounts: done
2016-09-20 08:17:53 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.summary_counts.tab
2016-09-20 08:17:53 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2016-09-20 08:17:53 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2016-09-20 08:17:53 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2016-09-20 08:17:53 INFO::coverage.R/calculateCoverage: starting...
2016-09-20 08:17:54 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:17:55 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:17:55 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000001/logs/progress.log
2016-09-20 08:17:57 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2016-09-20 08:17:57 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000002/logs/progress.log
2016-09-20 08:17:59 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2016-09-20 08:17:59 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/chunks/chunk_000003/logs/progress.log
2016-09-20 08:18:01 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2016-09-20 08:18:01 DEBUG::tools.R/processChunks: done
2016-09-20 08:18:02 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.coverage.RData
2016-09-20 08:18:02 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.coverage.bw
2016-09-20 08:18:02 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.summary_coverage.tab
2016-09-20 08:18:02 INFO::coverage.R/calculateCoverage: done
2016-09-20 08:18:02 INFO::analyzeVariants/analyzeVariants: starting ...
2016-09-20 08:18:02 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:18:04 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:18:04 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:18:04 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:18:04 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.raw_variants.RData
2016-09-20 08:18:04 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.filtered_variants.RData
2016-09-20 08:18:04 INFO::analyzeVariants.R/wrap.callVariants: ...done
2016-09-20 08:18:04 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2016-09-20 08:18:04 INFO::analyzeVariants.R/writeVCF: ...done
2016-09-20 08:18:04 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/results/test_pe.summary_variants.tab
2016-09-20 08:18:04 INFO::analyzeVariants/analyzeVariants: done
2016-09-20 08:18:04 INFO::Pipeline run successful.
2016-09-20 08:18:06 INFO::mergeLanes.R/doMergeLanes: starting...
2016-09-20 08:18:06 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 08:18:06 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.adapter_contaminated_1.RData
2016-09-20 08:18:06 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2016-09-20 08:18:06 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.adapter_contaminated_2.RData
2016-09-20 08:18:06 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
2016-09-20 08:18:06 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.summary_preprocess.tab
2016-09-20 08:18:06 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2016-09-20 08:18:06 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2016-09-20 08:18:06 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.summary_alignment.tab
2016-09-20 08:18:06 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.summary_analyzed_bamstats.tab
2016-09-20 08:18:06 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.summary_target_lengths.tab
2016-09-20 08:18:07 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2016-09-20 08:18:07 INFO::countGenomicFeatures.R/mergeCounts: starting...
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.counts_exon.tab
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.counts_gene.tab
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.counts_gene_coding.tab
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.counts_gene_exonic.tab
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.counts_intergenic.tab
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.counts_intron.tab
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.counts_transcript.tab
2016-09-20 08:18:07 INFO::countGenomicFeatures.R/mergeCounts: done
2016-09-20 08:18:07 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.summary_counts.tab
2016-09-20 08:18:07 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2016-09-20 08:18:07 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2016-09-20 08:18:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.coverage.RData
2016-09-20 08:18:08 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.coverage.bw
2016-09-20 08:18:08 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.mergeLanes.79f553c19cd0/merged/results/merged.summary_coverage.tab
2016-09-20 08:18:08 INFO::analyzeVariants/analyzeVariants: starting ...
2016-09-20 08:18:08 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:18:08 ERROR::tools.R/safeExecute: caught exception:
2016-09-20 08:18:08 ERROR::Error in open.connection(file, "rt"): cannot open the connection

2016-09-20 08:18:08 ERROR::tools.R/safeExecute: traceback:
2016-09-20 08:18:09 ERROR::38: open.connection(file, "rt")
2016-09-20 08:18:09 ERROR::37: open(file, "rt")
2016-09-20 08:18:09 ERROR::36: read.table(.get_genome(path(directory(x)), genome(x), chromosomes = TRUE), 
2016-09-20 08:18:09 ERROR::35: suppressWarnings({
2016-09-20 08:18:09 ERROR::34: seqinfo(genome)
2016-09-20 08:18:09 ERROR::33: seqinfo(genome)
2016-09-20 08:18:09 ERROR::32: normArgWhich(which, params$genome)
2016-09-20 08:18:09 ERROR::31: (function (genome, which = GRanges(), desired_read_group = NULL, 
2016-09-20 08:18:09 ERROR::30: do.call(BamTallyParam, bam.tally.args)
2016-09-20 08:18:09 ERROR::29: do.call(BamTallyParam, bam.tally.args)
2016-09-20 08:18:09 ERROR::28: (function (genome, read_pos_breaks = NULL, high_base_quality = 0L, 
2016-09-20 08:18:09 ERROR::27: do.call(TallyVariantsParam, args)
2016-09-20 08:18:09 ERROR::26: do.call(TallyVariantsParam, args)
2016-09-20 08:18:09 ERROR::25: buildTallyParam()
2016-09-20 08:18:09 ERROR::24: wrap.callVariants(bam.file)
2016-09-20 08:18:09 ERROR::23: callVariantsVariantTools(bam.file)
2016-09-20 08:18:09 ERROR::22: eval(expr, env)
2016-09-20 08:18:09 ERROR::21: try(eval(expr, env), silent = TRUE)
2016-09-20 08:18:09 ERROR::20: safeExecute({
2016-09-20 08:18:09 ERROR::19: analyzeVariants()
2016-09-20 08:18:09 ERROR::18: eval(expr, env)
2016-09-20 08:18:09 ERROR::17: try(eval(expr, env), silent = TRUE)
2016-09-20 08:18:09 ERROR::16: safeExecute({
2016-09-20 08:18:09 ERROR::15: doMergeLanes(indirs)
2016-09-20 08:18:09 ERROR::14: eval(expr, env)
2016-09-20 08:18:09 ERROR::13: try(eval(expr, env), silent = TRUE)
2016-09-20 08:18:09 ERROR::12: safeExecute({
2016-09-20 08:18:09 ERROR::11: mergeLanes(indirs, mergedir, prepend_str, num_cores = 1, preMergeChecks.do = FALSE, 
2016-09-20 08:18:09 ERROR::10: func()
2016-09-20 08:18:09 ERROR::9: system.time(func())
2016-09-20 08:18:09 ERROR::8: try(system.time(func()))
2016-09-20 08:18:09 ERROR::7: .executeTestCase(funcName, envir = sandbox, setUpFunc = .setUp, 
2016-09-20 08:18:09 ERROR::6: .sourceTestFile(testFile, testSuite$testFuncRegexp)
2016-09-20 08:18:09 ERROR::5: runTestSuite(testSuite)
2016-09-20 08:18:09 ERROR::4: eval(expr, envir, enclos)
2016-09-20 08:18:09 ERROR::3: eval(ei, envir)
2016-09-20 08:18:09 ERROR::2: withVisible(eval(ei, envir))
2016-09-20 08:18:09 ERROR::1: source(getPackageFile("unitTests/runTests.R"))
2016-09-20 08:18:09 ERROR::tools.R/safeExecute: caught exception:
2016-09-20 08:18:09 ERROR::Error in open.connection(file, "rt"): cannot open the connection

2016-09-20 08:18:09 ERROR::tools.R/safeExecute: traceback:
2016-09-20 08:18:09 ERROR::22: (function (e) 
2016-09-20 08:18:09 ERROR::21: stop(z$e)
2016-09-20 08:18:09 ERROR::20: safeExecute({
2016-09-20 08:18:09 ERROR::19: analyzeVariants()
2016-09-20 08:18:09 ERROR::18: eval(expr, env)
2016-09-20 08:18:09 ERROR::17: try(eval(expr, env), silent = TRUE)
2016-09-20 08:18:09 ERROR::16: safeExecute({
2016-09-20 08:18:09 ERROR::15: doMergeLanes(indirs)
2016-09-20 08:18:09 ERROR::14: eval(expr, env)
2016-09-20 08:18:09 ERROR::13: try(eval(expr, env), silent = TRUE)
2016-09-20 08:18:09 ERROR::12: safeExecute({
2016-09-20 08:18:09 ERROR::11: mergeLanes(indirs, mergedir, prepend_str, num_cores = 1, preMergeChecks.do = FALSE, 
2016-09-20 08:18:09 ERROR::10: func()
2016-09-20 08:18:09 ERROR::9: system.time(func())
2016-09-20 08:18:09 ERROR::8: try(system.time(func()))
2016-09-20 08:18:09 ERROR::7: .executeTestCase(funcName, envir = sandbox, setUpFunc = .setUp, 
2016-09-20 08:18:09 ERROR::6: .sourceTestFile(testFile, testSuite$testFuncRegexp)
2016-09-20 08:18:09 ERROR::5: runTestSuite(testSuite)
2016-09-20 08:18:09 ERROR::4: eval(expr, envir, enclos)
2016-09-20 08:18:09 ERROR::3: eval(ei, envir)
2016-09-20 08:18:09 ERROR::2: withVisible(eval(ei, envir))
2016-09-20 08:18:09 ERROR::1: source(getPackageFile("unitTests/runTests.R"))
2016-09-20 08:18:09 ERROR::tools.R/safeExecute: caught exception:
2016-09-20 08:18:09 ERROR::Error in open.connection(file, "rt"): cannot open the connection

2016-09-20 08:18:09 ERROR::tools.R/safeExecute: traceback:
2016-09-20 08:18:09 ERROR::18: (function (e) 
2016-09-20 08:18:09 ERROR::17: stop(z$e)
2016-09-20 08:18:09 ERROR::16: safeExecute({
2016-09-20 08:18:09 ERROR::15: doMergeLanes(indirs)
2016-09-20 08:18:09 ERROR::14: eval(expr, env)
2016-09-20 08:18:09 ERROR::13: try(eval(expr, env), silent = TRUE)
2016-09-20 08:18:09 ERROR::12: safeExecute({
2016-09-20 08:18:09 ERROR::11: mergeLanes(indirs, mergedir, prepend_str, num_cores = 1, preMergeChecks.do = FALSE, 
2016-09-20 08:18:09 ERROR::10: func()
2016-09-20 08:18:09 ERROR::9: system.time(func())
2016-09-20 08:18:09 ERROR::8: try(system.time(func()))
2016-09-20 08:18:09 ERROR::7: .executeTestCase(funcName, envir = sandbox, setUpFunc = .setUp, 
2016-09-20 08:18:09 ERROR::6: .sourceTestFile(testFile, testSuite$testFuncRegexp)
2016-09-20 08:18:09 ERROR::5: runTestSuite(testSuite)
2016-09-20 08:18:09 ERROR::4: eval(expr, envir, enclos)
2016-09-20 08:18:09 ERROR::3: eval(ei, envir)
2016-09-20 08:18:09 ERROR::2: withVisible(eval(ei, envir))
2016-09-20 08:18:09 ERROR::1: source(getPackageFile("unitTests/runTests.R"))
Timing stopped at: 27.228 19.408 54.358 
Error in open.connection(file, "rt") : cannot open the connection
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0 0 0.001 
Error in DEACTIVATED("Skipped markDuplicates() test") : 
  Skipped markDuplicates() test
 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/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:18:12 INFO::preprocessReads.R/preprocessReads: starting...
2016-09-20 08:18:12 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:18:12 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_2.fastq
2016-09-20 08:18:12 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:18:14 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:18:14 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/chunks/chunk_000001/logs/progress.log
2016-09-20 08:18:16 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2016-09-20 08:18:16 DEBUG::tools.R/processChunks: done
2016-09-20 08:18:16 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 08:18:16 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/results/test_pe.adapter_contaminated_1.RData
2016-09-20 08:18:16 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2016-09-20 08:18:16 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/results/test_pe.adapter_contaminated_2.RData
2016-09-20 08:18:16 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
2016-09-20 08:18:16 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/results/test_pe.summary_preprocess.tab
2016-09-20 08:18:16 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/bams/processed.aligner_input_1.fastq ...
2016-09-20 08:18:17 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/bams/processed.aligner_input_2.fastq ...
2016-09-20 08:18:17 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/reports/shortReadReport_1 ...
2016-09-20 08:18:19 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.preprocessReads.79f52a80f78d/reports/shortReadReport_2 ...
2016-09-20 08:18:21 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:18:23 INFO::preprocessReads.R/preprocessReads: starting...
2016-09-20 08:18:23 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:18:23 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_2.fastq
2016-09-20 08:18:23 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:18:25 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:18:25 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/chunks/chunk_000001/logs/progress.log
2016-09-20 08:18:27 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2016-09-20 08:18:27 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/chunks/chunk_000002/logs/progress.log
2016-09-20 08:18:30 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2016-09-20 08:18:30 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/chunks/chunk_000003/logs/progress.log
2016-09-20 08:18:33 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2016-09-20 08:18:33 DEBUG::tools.R/processChunks: done
2016-09-20 08:18:33 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 08:18:33 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/results/test_pe.adapter_contaminated_1.RData
2016-09-20 08:18:33 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2016-09-20 08:18:33 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/results/test_pe.adapter_contaminated_2.RData
2016-09-20 08:18:33 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
2016-09-20 08:18:33 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/results/test_pe.summary_preprocess.tab
2016-09-20 08:18:33 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/bams/processed.aligner_input_1.fastq ...
2016-09-20 08:18:33 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/bams/processed.aligner_input_2.fastq ...
2016-09-20 08:18:33 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/reports/shortReadReport_1 ...
2016-09-20 08:18:35 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.preprocessReads.minichunks.79f52818e558/reports/shortReadReport_2 ...
2016-09-20 08:18:37 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:18:40 INFO::preprocessReads.R/preprocessReads: starting...
2016-09-20 08:18:40 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/unit_tests_1.fastq
2016-09-20 08:18:40 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:18:41 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:18:41 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp8SYYBa/test.preprocessReads_single_end.79f511b69d35/chunks/chunk_000001/logs/progress.log
2016-09-20 08:18:44 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2016-09-20 08:18:44 DEBUG::tools.R/processChunks: done
2016-09-20 08:18:44 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 08:18:44 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads_single_end.79f511b69d35/results/test_se.adapter_contaminated_1.RData
2016-09-20 08:18:44 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
2016-09-20 08:18:44 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.preprocessReads_single_end.79f511b69d35/results/test_se.summary_preprocess.tab
2016-09-20 08:18:44 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp8SYYBa/test.preprocessReads_single_end.79f511b69d35/bams/processed.aligner_input_1.fastq ...
2016-09-20 08:18:44 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp8SYYBa/test.preprocessReads_single_end.79f511b69d35/reports/shortReadReport_1 ...
2016-09-20 08:18:46 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.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:18:52 INFO::preprocessReads.R/preprocessReads: starting...
2016-09-20 08:18:52 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2016-09-20 08:18:52 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2016-09-20 08:18:52 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:18:53 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:18:53 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2016-09-20 08:18:56 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2016-09-20 08:18:56 DEBUG::tools.R/processChunks: done
2016-09-20 08:18:56 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2016-09-20 08:18:56 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2016-09-20 08:18:56 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2016-09-20 08:18:56 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2016-09-20 08:18:56 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
2016-09-20 08:18:56 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2016-09-20 08:18:56 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2016-09-20 08:18:56 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2016-09-20 08:18:56 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2016-09-20 08:18:58 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2016-09-20 08:19:00 INFO::preprocessReads.R/preprocessReads: done
2016-09-20 08:19:01 INFO::alignReads.R/alignReads: starting alignment...
2016-09-20 08:19:01 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:19:02 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:19:02 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2016-09-20 08:19:07 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.081 minutes
2016-09-20 08:19:07 DEBUG::tools.R/processChunks: done
2016-09-20 08:19:07 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2016-09-20 08:19:07 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2016-09-20 08:19:07 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2016-09-20 08:19:07 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2016-09-20 08:19:07 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2016-09-20 08:19:07 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2016-09-20 08:19:07 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2016-09-20 08:19:07 INFO::alignReads.R/alignReads: done
2016-09-20 08:19:08 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2016-09-20 08:19:08 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:19:09 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:19:09 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2016-09-20 08:19:12 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2016-09-20 08:19:12 DEBUG::tools.R/processChunks: done
2016-09-20 08:19:12 INFO::countGenomicFeatures.R/mergeCounts: starting...
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.counts_transcript.tab
2016-09-20 08:19:12 INFO::countGenomicFeatures.R/mergeCounts: done
2016-09-20 08:19:12 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2016-09-20 08:19:12 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2016-09-20 08:19:12 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2016-09-20 08:19:12 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2016-09-20 08:19:12 INFO::coverage.R/calculateCoverage: starting...
2016-09-20 08:19:12 DEBUG::tools.R/processChunks: starting...
2016-09-20 08:19:14 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2016-09-20 08:19:14 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2016-09-20 08:19:16 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2016-09-20 08:19:16 DEBUG::tools.R/processChunks: done
2016-09-20 08:19:16 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2016-09-20 08:19:16 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2016-09-20 08:19:17 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2016-09-20 08:19:17 INFO::coverage.R/calculateCoverage: done
2016-09-20 08:19:17 INFO::analyzeVariants/analyzeVariants: starting ...
2016-09-20 08:19:17 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2016-09-20 08:19:19 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2016-09-20 08:19:19 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2016-09-20 08:19:20 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2016-09-20 08:19:20 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2016-09-20 08:19:20 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2016-09-20 08:19:20 INFO::analyzeVariants.R/wrap.callVariants: ...done
2016-09-20 08:19:20 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2016-09-20 08:19:20 INFO::analyzeVariants.R/writeVCF: ...done
2016-09-20 08:19:20 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2016-09-20 08:19:20 INFO::analyzeVariants/analyzeVariants: done
2016-09-20 08:19:20 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp8SYYBa/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/config/default-config.txt 
2016-09-20 08:19:22 INFO::io.R/saveWithID: saving file= /tmp/Rtmp8SYYBa/test.calcTargetLengths.79f55d43da88/results/test_pe.summary_target_lengths.tab
 done successfully.



Executing test function test.sclapply  ... Timing stopped at: 1.484 51.12 28.935 
Error in mcfork(detached) : 
  unable to fork, possible reason: Cannot allocate memory
 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 Sep 20 08:19:53 2016 
*********************************************** 
Number of test functions: 63 
Number of deactivated test functions: 9 
Number of errors: 3 
Number of failures: 0 

 
1 Test Suite : 
HTSeqGenie unit testing - 63 test functions, 3 errors, 0 failures
ERROR in test.annotateVariants: Error in annotateVariants(vcf) : 
  variant_effect_predictor.pl failed.--vcf --sift b --polyphen b --protein --check_existing --check_alleles --symbol --canonical --ccds --maf_1kg --maf_esp --cache --force_overwrite --no_stats --fork 2 --input_file /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/braf_v600.vcf --output_file /tmp/Rtmp8SYYBa/test.annotateVariants.79f52a878016/results/test_pe.variants_vep.vcf
DEACTIVATED test.callVariantsGATK: callVariantsGATK() tests need gatk.path option set
DEACTIVATED test.callVariantsGATK.withFiltering: callVariantsGATK() tests need gatk.path option set
DEACTIVATED test.checkGATKJar: checkGATKJar() test needs gatk.path option set
DEACTIVATED test.gatk: gatk() tests need gatk.path option set
DEACTIVATED test.realignIndels: test.realignIndels() tests need gatk.path option set
DEACTIVATED test.realignIndelsGATK: realignIndelsGATK() tests need gatk.path option set
DEACTIVATED test.realignIndelsGATK.parallel: realignIndelsGATK() tests need gatk.path option set
ERROR in test.mergeLanes: Error in open.connection(file, "rt") : cannot open the connection
DEACTIVATED test.markDuplicates: Skipped markDuplicates() test
DEACTIVATED test.markDuplicates_w_outfile: Skipped markDuplicates() test
ERROR in test.sclapply: Error in mcfork(detached) : 
  unable to fork, possible reason: Cannot allocate memory



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (23.68 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (15.51 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (1.09 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants: ERROR !! 
Error in annotateVariants(vcf) : 
  variant_effect_predictor.pl failed.--vcf --sift b --polyphen b --protein --check_existing --check_alleles --symbol --canonical --ccds --maf_1kg --maf_esp --cache --force_overwrite --no_stats --fork 2 --input_file /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/test-data/braf_v600.vcf --output_file /tmp/Rtmp8SYYBa/test.annotateVariants.79f52a878016/results/test_pe.variants_vep.vcf
test.callVariantsVariantTools.genotype: (2 checks) ... OK (28.62 seconds)
test.wrap.callVariants: (4 checks) ... OK (1.71 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (3.12 seconds)
test.wrap.callVariants.parallel: (1 checks) ... OK (4.77 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (1.51 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.75 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.96 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (533.58 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (388.32 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.59 seconds)
test.isSparse: (5 checks) ... OK (0.07 seconds)
test.mergeCoverage: (1 checks) ... OK (0.69 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (0.6 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (1.86 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (2.4 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (3.77 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.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.08 seconds)
test.isAdapter: (5 checks) ... OK (0.04 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (2.34 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (2.48 seconds)
test.getRRNAIds: (1 checks) ... OK (0.64 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.65 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.06 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.05 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/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.13 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 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (1.9 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (1.99 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (1.86 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (1.9 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (4.02 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.1 seconds)
test.getObjectFilename: (4 checks) ... OK (0.22 seconds)
test.safeUnlink: (2 checks) ... OK (0.44 seconds)
test.writeAudit: (0 checks) ... OK (3.29 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: ERROR !! 
Error in open.connection(file, "rt") : cannot open the connection
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/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.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (10.54 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.87 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.07 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.05 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.06 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.14 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.04 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (30.28 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (1.88 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: ERROR !! 
Error in mcfork(detached) : 
  unable to fork, possible reason: Cannot allocate memory
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.03 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.1 seconds) 

Error in eval(expr, envir, enclos) : 
  runTests.R: failed to run unit tests, see /home/biocbuild/bbs-3.4-bioc/meat/HTSeqGenie.Rcheck/tests/HTSeqGenie-runit.txt for details
Calls: source -> withVisible -> eval -> eval
Execution halted

HTSeqGenie.Rcheck/00install.out:

* installing *source* package ‘HTSeqGenie’ ...
** R
** inst
** preparing package for lazy loading
** help
*** installing help indices
** building package indices
** installing vignettes
** testing if installed package can be loaded
* DONE (HTSeqGenie)

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings:

nameusersystemelapsed
HTSeqGenie0.0000.0000.001
buildGenomicFeaturesFromTxDb000
runPipeline0.0040.0000.001