| Back to Build/check report for BioC 3.17: simplified long |
|
This page was generated on 2023-02-27 02:34:35 -0000 (Mon, 27 Feb 2023).
| Hostname | OS | Arch (*) | R version | Installed pkgs |
|---|---|---|---|---|
| kunpeng1 | Linux (Ubuntu 22.04.1 LTS) | aarch64 | R Under development (unstable) (2023-01-14 r83615) -- "Unsuffered Consequences" | 4259 |
| Click on any hostname to see more info about the system (e.g. compilers) (*) as reported by 'uname -p', except on Windows and Mac OS X | ||||
|
To the developers/maintainers of the HTSeqGenie package: - Please allow up to 24 hours (and sometimes 48 hours) for your latest push to git@git.bioconductor.org:packages/HTSeqGenie.git to reflect on this report. See How and When does the builder pull? When will my changes propagate? for more information. - Make sure to use the following settings in order to reproduce any error or warning you see on this page. |
| Package 916/2169 | Hostname | OS / Arch | INSTALL | BUILD | CHECK | BUILD BIN | ||||||||
| HTSeqGenie 4.29.1 (landing page) Jens Reeder
| kunpeng1 | Linux (Ubuntu 22.04.1 LTS) / aarch64 | OK | OK | OK | |||||||||
| Package: HTSeqGenie |
| Version: 4.29.1 |
| Command: /home/biocbuild/bbs-3.17-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.17-bioc/R/library --timings HTSeqGenie_4.29.1.tar.gz |
| StartedAt: 2023-02-24 12:35:47 -0000 (Fri, 24 Feb 2023) |
| EndedAt: 2023-02-24 12:54:46 -0000 (Fri, 24 Feb 2023) |
| EllapsedTime: 1138.2 seconds |
| RetCode: 0 |
| Status: OK |
| CheckDir: HTSeqGenie.Rcheck |
| Warnings: 0 |
##############################################################################
##############################################################################
###
### Running command:
###
### /home/biocbuild/bbs-3.17-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.17-bioc/R/library --timings HTSeqGenie_4.29.1.tar.gz
###
##############################################################################
##############################################################################
* using log directory ‘/home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck’
* using R Under development (unstable) (2023-01-14 r83615)
* using platform: aarch64-unknown-linux-gnu (64-bit)
* R was compiled by
gcc (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0
GNU Fortran (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0
* running under: Ubuntu 22.04.1 LTS
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.29.1’
* 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 ... OK
* 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 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’
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’
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 quantile ranges resize seqinfo sjobs subseq
viewMeans
Consider adding
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 ... OK
* checking for code/documentation mismatches ... OK
* checking Rd \usage sections ... OK
* checking Rd contents ... OK
* checking for unstated dependencies in examples ... OK
* checking files in ‘vignettes’ ... OK
* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
Running ‘doRUnit.R’
OK
* checking for unstated dependencies in vignettes ... OK
* checking package vignettes in ‘inst/doc’ ... OK
* checking running R code from vignettes ...
‘HTSeqGenie.Rnw’... OK
OK
* checking re-building of vignette outputs ... OK
* checking PDF version of manual ... OK
* DONE
Status: 5 NOTEs
See
‘/home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck/00check.log’
for details.
HTSeqGenie.Rcheck/00install.out
############################################################################## ############################################################################## ### ### Running command: ### ### /home/biocbuild/bbs-3.17-bioc/R/bin/R CMD INSTALL HTSeqGenie ### ############################################################################## ############################################################################## * installing to library ‘/home/biocbuild/bbs-3.17-bioc/R/library’ * installing *source* package ‘HTSeqGenie’ ... ** using staged installation ** R ** inst ** byte-compile and prepare package for lazy loading ** help *** installing help indices ** building package indices ** installing vignettes ** testing if installed package can be loaded from temporary location ** testing if installed package can be loaded from final location ** testing if installed package keeps a record of temporary installation path * DONE (HTSeqGenie)
HTSeqGenie.Rcheck/tests/doRUnit.Rout
R Under development (unstable) (2023-01-14 r83615) -- "Unsuffered Consequences"
Copyright (C) 2023 The R Foundation for Statistical Computing
Platform: aarch64-unknown-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
Attaching package: 'BiocGenerics'
The following objects are masked from 'package:stats':
IQR, mad, sd, var, xtabs
The following objects are masked from 'package:base':
Filter, Find, Map, Position, Reduce, anyDuplicated, aperm, append,
as.data.frame, basename, cbind, colnames, dirname, do.call,
duplicated, eval, evalq, get, grep, grepl, intersect, is.unsorted,
lapply, mapply, match, mget, order, paste, pmax, pmax.int, pmin,
pmin.int, rank, rbind, rownames, sapply, setdiff, sort, table,
tapply, union, unique, unsplit, which.max, which.min
Loading required package: S4Vectors
Loading required package: stats4
Attaching package: 'S4Vectors'
The following objects are masked from 'package:base':
I, expand.grid, unname
Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector
Attaching package: 'Biostrings'
The following object is masked from 'package:base':
strsplit
Loading required package: ShortRead
Loading required package: BiocParallel
Loading required package: GenomicAlignments
Loading required package: SummarizedExperiment
Loading required package: MatrixGenerics
Loading required package: matrixStats
Attaching package: 'MatrixGenerics'
The following objects are masked from 'package:matrixStats':
colAlls, colAnyNAs, colAnys, colAvgsPerRowSet, colCollapse,
colCounts, colCummaxs, colCummins, colCumprods, colCumsums,
colDiffs, colIQRDiffs, colIQRs, colLogSumExps, colMadDiffs,
colMads, colMaxs, colMeans2, colMedians, colMins, colOrderStats,
colProds, colQuantiles, colRanges, colRanks, colSdDiffs, colSds,
colSums2, colTabulates, colVarDiffs, colVars, colWeightedMads,
colWeightedMeans, colWeightedMedians, colWeightedSds,
colWeightedVars, rowAlls, rowAnyNAs, rowAnys, rowAvgsPerColSet,
rowCollapse, rowCounts, rowCummaxs, rowCummins, rowCumprods,
rowCumsums, rowDiffs, rowIQRDiffs, rowIQRs, rowLogSumExps,
rowMadDiffs, rowMads, rowMaxs, rowMeans2, rowMedians, rowMins,
rowOrderStats, rowProds, rowQuantiles, rowRanges, rowRanks,
rowSdDiffs, rowSds, rowSums2, rowTabulates, rowVarDiffs, rowVars,
rowWeightedMads, rowWeightedMeans, rowWeightedMedians,
rowWeightedSds, rowWeightedVars
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")'.
Attaching package: 'Biobase'
The following object is masked from 'package:MatrixGenerics':
rowMedians
The following objects are masked from 'package:matrixStats':
anyMissing, rowMedians
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/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:42:15.391781 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-24 12:42:15.401837 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:42:15.407602 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-02-24 12:42:15.410526 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:42:18.596149 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:42:18.598094 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/chunks/chunk_000001/logs/progress.log
2023-02-24 12:42:21.489846 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2023-02-24 12:42:21.492081 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/chunks/chunk_000002/logs/progress.log
2023-02-24 12:42:24.383136 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.048 minutes
2023-02-24 12:42:24.385015 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/chunks/chunk_000003/logs/progress.log
2023-02-24 12:42:27.262231 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2023-02-24 12:42:27.308397 DEBUG::tools.R/processChunks: done
2023-02-24 12:42:27.313378 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:42:27.316517 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/results/test_pe.adapter_contaminated_1.RData
2023-02-24 12:42:27.320331 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-24 12:42:27.322744 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/results/test_pe.adapter_contaminated_2.RData
2023-02-24 12:42:27.33515 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
2023-02-24 12:42:27.338155 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/results/test_pe.summary_preprocess.tab
2023-02-24 12:42:27.342936 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/bams/processed.aligner_input_1.fastq ...
2023-02-24 12:42:27.348712 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/bams/processed.aligner_input_2.fastq ...
2023-02-24 12:42:27.353417 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/reports/shortReadReport_1 ...
2023-02-24 12:42:29.207484 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/reports/shortReadReport_2 ...
2023-02-24 12:42:30.666798 INFO::preprocessReads.R/preprocessReads: done
2023-02-24 12:42:30.72242 INFO::alignReads.R/alignReads: starting alignment...
2023-02-24 12:42:30.729404 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:42:33.890332 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:42:33.892461 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/chunks/chunk_000001/logs/progress.log
2023-02-24 12:42:37.013781 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2023-02-24 12:42:37.016067 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:42:39.82855 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-02-24 12:42:39.830878 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:42:42.609956 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-02-24 12:42:42.613368 DEBUG::tools.R/processChunks: done
2023-02-24 12:42:42.615345 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:42:42.922249 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-24 12:42:42.937968 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/results/test_pe.summary_alignment.tab
2023-02-24 12:42:42.948647 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/results/test_pe.summary_analyzed_bamstats.tab
2023-02-24 12:42:42.951147 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-24 12:42:43.253886 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.59c1b6c526cef/results/test_pe.summary_target_lengths.tab
2023-02-24 12:42:43.312715 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-24 12:42:43.314184 INFO::alignReads.R/alignReads: done
done successfully.
Executing test function test.alignReads.sparsechunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:42:43.649458 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-24 12:42:43.653778 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:42:43.739906 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2023-02-24 12:42:43.746636 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:42:43.750971 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-02-24 12:42:43.753615 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:42:46.998165 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:42:47.000237 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/chunks/chunk_000001/logs/progress.log
2023-02-24 12:42:49.860281 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2023-02-24 12:42:49.862325 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/chunks/chunk_000002/logs/progress.log
2023-02-24 12:42:52.700292 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-02-24 12:42:52.702332 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/chunks/chunk_000003/logs/progress.log
2023-02-24 12:42:55.629065 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2023-02-24 12:42:55.631047 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/chunks/chunk_000004/logs/progress.log
2023-02-24 12:42:58.450458 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.047 minutes
2023-02-24 12:42:58.500242 DEBUG::tools.R/processChunks: done
2023-02-24 12:42:58.50598 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:42:58.509646 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/results/test_pe.adapter_contaminated_1.RData
2023-02-24 12:42:58.514225 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-24 12:42:58.517083 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/results/test_pe.adapter_contaminated_2.RData
2023-02-24 12:42:58.531707 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
2023-02-24 12:42:58.535037 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/results/test_pe.summary_preprocess.tab
2023-02-24 12:42:58.540187 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/bams/processed.aligner_input_1.fastq ...
2023-02-24 12:42:58.546603 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/bams/processed.aligner_input_2.fastq ...
2023-02-24 12:42:58.551265 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/reports/shortReadReport_1 ...
2023-02-24 12:43:00.266637 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.alignReads.sparsechunks.59c1b6b558c83/reports/shortReadReport_2 ...
2023-02-24 12:43:01.640234 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.alignReadsOneSingleEnd ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:43:01.885354 INFO::alignReads.R/alignReadsChunk: running gsnap...
2023-02-24 12:43:01.891584 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/Rtmp4BoLuA/test.alignReadsOneSingleEnd.59c1b4212d8e2/bams/test.alignReads /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2023-02-24 12:43:02.121216 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2023-02-24 12:43:02.256408 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReadsOneSingleEnd.59c1b4212d8e2/results/test.alignReads.summary_alignment.tab
2023-02-24 12:43:02.311196 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.alignReadsOneSingleEnd.59c1b4212d8e2/results/test.alignReads.summary_analyzed_bamstats.tab
2023-02-24 12:43:02.313505 INFO::alignReads.R/alignReadsChunk: done
done successfully.
Executing test function test.annotateVariants ... Timing stopped at: 0.003 0 0.003
Error in DEACTIVATED("Skipped annotateVariants() test") :
Skipped annotateVariants() test
In addition: There were 11 warnings (use warnings() to see them)
done successfully.
Executing test function test.callVariantsVariantTools.genotype ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:43:02.759867 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.genotype.59c1b99c4e8e/results/test_pe.coverage.RData
2023-02-24 12:43:02.762416 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4BoLuA/test.genotype.59c1b99c4e8e/results/test_pe.coverage.bw
2023-02-24 12:43:02.946357 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.genotype.59c1b99c4e8e/results/test_pe.summary_coverage.tab
2023-02-24 12:43:02.948699 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:43:14.674328 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:43:14.796118 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:43:14.818769 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:43:14.82067 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.genotype.59c1b99c4e8e/results/test_pe.raw_variants.RData
2023-02-24 12:43:14.823948 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.genotype.59c1b99c4e8e/results/test_pe.filtered_variants.RData
2023-02-24 12:43:14.825763 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-24 12:43:14.827341 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-24 12:43:15.373598 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-24 12:43:15.375196 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2023-02-24 12:44:21.317795 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-24 12:44:21.936933 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-24 12:44:21.938166 INFO::analyzeVariants.R/.callGenotypes: done
[W::bcf_hdr_check_sanity] PL should be declared as Number=G
done successfully.
Executing test function test.wrap.callVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:44:22.562876 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:44:33.81605 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:44:33.915772 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:44:33.937782 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:44:33.939607 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.59c1b303dfe30/results/test_pe.raw_variants.RData
2023-02-24 12:44:33.942879 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.59c1b303dfe30/results/test_pe.filtered_variants.RData
2023-02-24 12:44:33.944653 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.filters ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:44:34.133533 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:44:44.658225 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:44:44.728272 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:44:44.748949 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:44:44.750652 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.filters.59c1b207cae68/results/test_pe.raw_variants.RData
2023-02-24 12:44:44.753772 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.filters.59c1b207cae68/results/test_pe.filtered_variants.RData
2023-02-24 12:44:44.755369 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-24 12:44:44.756878 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:44:55.350089 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:44:55.397863 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:44:55.419187 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:44:55.420875 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.filters.59c1b207cae68/results/test_pe.raw_variants.RData
2023-02-24 12:44:55.424189 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.filters.59c1b207cae68/results/test_pe.filtered_variants.RData
2023-02-24 12:44:55.426955 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.which ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:44:55.648402 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:44:55.650193 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2023-02-24 12:44:58.126368 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:44:58.220008 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:44:58.24084 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:44:58.242561 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.which.59c1b584827fa/results/test_pe.raw_variants.RData
2023-02-24 12:44:58.244617 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.wrap.callVariants.which.59c1b584827fa/results/test_pe.filtered_variants.RData
2023-02-24 12:44:58.246247 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.writeVCF.NULL ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:44:58.438578 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-24 12:44:58.44014 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.writeVCF.vcfStat ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:44:58.69539 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-24 12:44:58.996435 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.isFirstFragment ... done successfully.
Executing test function test.buildCountsGRangesList ... 403 genes were dropped because they have exons located on both strands
of the same reference sequence or on more than one reference sequence,
so cannot be represented by a single genomic range.
Use 'single.strand.genes.only=FALSE' to get all the genes in a
GRangesList object, or use suppressMessages() to suppress this message.
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 ... 2023-02-24 12:46:13.065498 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/xbdrokls/merged/results/bla.coverage.RData
2023-02-24 12:46:13.068699 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4BoLuA/xbdrokls/merged/results/bla.coverage.bw
2023-02-24 12:46:13.179096 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/xbdrokls/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.mergeCoverage.sparse ... 2023-02-24 12:46:14.449094 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/aorefqli/merged/results/bla.coverage.RData
2023-02-24 12:46:14.45143 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4BoLuA/aorefqli/merged/results/bla.coverage.bw
2023-02-24 12:46:14.467212 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/aorefqli/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.checkConfig.analyzeVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.findTemplate ... done successfully.
Executing test function test.checkConfig ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.checkConfig.alignReads ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.getConfig ... done successfully.
Executing test function test.loadConfig ... done successfully.
Executing test function test.parseDCF ... done successfully.
Executing test function test.updateConfig ... done successfully.
Executing test function test.getAdapterSeqs ... done successfully.
Executing test function test.isAdapter ... done successfully.
Executing test function test.isAdapter3.primeEnd ... done successfully.
Executing test function test.detectRRNA ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:16.382201 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-02-24 12:46:16.383799 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4BoLuA/test.detectRRNA.59c1b1e5f437b/bams/rRNA_contam/input1.fastq
2023-02-24 12:46:16.388385 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/Rtmp4BoLuA/test.detectRRNA.59c1b1e5f437b/bams/rRNA_contam/test_se /tmp/Rtmp4BoLuA/test.detectRRNA.59c1b1e5f437b/bams/rRNA_contam/input1.fastq 2>&1
2023-02-24 12:46:16.539893 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-02-24 12:46:16.541319 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.detectRRNA.paired_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:16.787795 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-02-24 12:46:16.789209 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4BoLuA/test.detectRRNA.paired_end.59c1b5d58818d/bams/rRNA_contam/input1.fastq
2023-02-24 12:46:16.791438 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4BoLuA/test.detectRRNA.paired_end.59c1b5d58818d/bams/rRNA_contam/input2.fastq
2023-02-24 12:46:16.794736 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/Rtmp4BoLuA/test.detectRRNA.paired_end.59c1b5d58818d/bams/rRNA_contam/test_pe /tmp/Rtmp4BoLuA/test.detectRRNA.paired_end.59c1b5d58818d/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp4BoLuA/test.detectRRNA.paired_end.59c1b5d58818d/bams/rRNA_contam/input2.fastq 2>&1
2023-02-24 12:46:17.100281 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-02-24 12:46:17.101787 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.getRRNAIds ... 2023-02-24 12:46:17.131896 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/Rtmp4BoLuA/test_get_rRNA_idsmulxpaez/test_pe /tmp/Rtmp4BoLuA/test_get_rRNA_idsmulxpaez/1.fastq -a paired /tmp/Rtmp4BoLuA/test_get_rRNA_idsmulxpaez/2.fastq 2>&1
done successfully.
Executing test function test.getRRNAIds_random ... 2023-02-24 12:46:17.455381 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/Rtmp4BoLuA/test_get_rRNAIds_randomtkvaqydg/test_pe /tmp/Rtmp4BoLuA/test_get_rRNAIds_randomtkvaqydg/1.fastq 2>&1
done successfully.
Executing test function test.filterByLength ... 2023-02-24 12:46:17.689221 INFO::filterQuality.R/filterQuality: filterByLength...
2023-02-24 12:46:17.691239 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2023-02-24 12:46:17.692515 INFO::filterQuality.R/filterByLength: done
2023-02-24 12:46:17.758315 INFO::filterQuality.R/filterQuality: filterByLength...
2023-02-24 12:46:17.759616 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2023-02-24 12:46:17.760843 INFO::filterQuality.R/filterByLength: done
done successfully.
Executing test function test.isAboveQualityThresh ... done successfully.
Executing test function test.trimTailsByQuality ... 2023-02-24 12:46:17.834123 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-24 12:46:17.846898 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-24 12:46:17.848465 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-24 12:46:17.855088 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-24 12:46:17.856598 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-24 12:46:17.86321 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-24 12:46:17.864712 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-24 12:46:17.871358 INFO::preprocessReads.R/preprocessReadsChunk: done
done successfully.
Executing test function test.callVariantsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
In addition: There were 50 or more warnings (use warnings() to see the first 50)
done successfully.
Executing test function test.callVariantsGATK.withFiltering ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
done successfully.
Executing test function test.checkGATKJar ... Timing stopped at: 0 0 0.001
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") :
checkGATKJar() test needs gatk.path option set
done successfully.
Executing test function test.excludeVariantsByRegion ... done successfully.
Executing test function test.gatk ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") :
gatk() tests need gatk.path option set
done successfully.
Executing test function test.realignIndels ... Timing stopped at: 0 0 0.001
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.001 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/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:18.325763 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:18.329216 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
done successfully.
Executing test function test.FastQStreamer.getReads.pefq.subsample ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:18.622019 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:18.78409 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-24 12:46:18.787957 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:18.791188 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
done successfully.
Executing test function test.FastQStreamer.getReads.segz ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:19.1795 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/reads.fastq.gz
done successfully.
Executing test function test.FastQStreamer.getReads.truncated ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:19.428242 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/truncated.fastq.gz
done successfully.
Executing test function test.FastQStreamer.subsampler.isdeterministic ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:19.702044 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:19.827191 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-24 12:46:19.830867 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:19.834144 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:20.191801 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:20.268523 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-24 12:46:20.272022 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:20.275296 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
done successfully.
Executing test function test.createTmpDir ... done successfully.
Executing test function test.detectQualityInFASTQFile ... done successfully.
Executing test function test.getObjectFilename ... done successfully.
Executing test function test.safeUnlink ... done successfully.
Executing test function test.writeAudit ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.mergeLanes ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:46:21.451939 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-24 12:46:21.459978 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:46:21.465254 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-02-24 12:46:21.468652 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:46:25.40589 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:46:25.409014 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000001/logs/progress.log
2023-02-24 12:46:28.229291 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-02-24 12:46:28.231603 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000002/logs/progress.log
2023-02-24 12:46:31.014148 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-02-24 12:46:31.016301 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000003/logs/progress.log
2023-02-24 12:46:33.758729 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-02-24 12:46:33.825045 DEBUG::tools.R/processChunks: done
2023-02-24 12:46:33.828976 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:46:33.831646 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.adapter_contaminated_1.RData
2023-02-24 12:46:33.834949 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-24 12:46:33.837416 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.adapter_contaminated_2.RData
2023-02-24 12:46:33.849882 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
2023-02-24 12:46:33.852813 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.summary_preprocess.tab
2023-02-24 12:46:33.856592 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/bams/processed.aligner_input_1.fastq ...
2023-02-24 12:46:33.862468 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/bams/processed.aligner_input_2.fastq ...
2023-02-24 12:46:33.86723 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/reports/shortReadReport_1 ...
2023-02-24 12:46:35.696983 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/reports/shortReadReport_2 ...
2023-02-24 12:46:37.195098 INFO::preprocessReads.R/preprocessReads: done
2023-02-24 12:46:37.27476 INFO::alignReads.R/alignReads: starting alignment...
2023-02-24 12:46:37.280305 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:46:40.805492 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:46:40.807717 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000001/logs/progress.log
2023-02-24 12:46:43.480517 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2023-02-24 12:46:43.482829 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:46:46.230673 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-02-24 12:46:46.233199 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:46:48.950377 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2023-02-24 12:46:48.95397 DEBUG::tools.R/processChunks: done
2023-02-24 12:46:48.956137 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:46:49.253362 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-24 12:46:49.264296 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.summary_alignment.tab
2023-02-24 12:46:49.274845 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.summary_analyzed_bamstats.tab
2023-02-24 12:46:49.277616 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-24 12:46:49.567282 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.summary_target_lengths.tab
2023-02-24 12:46:49.630837 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-24 12:46:49.632347 INFO::alignReads.R/alignReads: done
2023-02-24 12:46:49.71184 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-02-24 12:46:49.734667 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:46:53.778922 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:46:53.781434 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000001/logs/progress.log
2023-02-24 12:46:56.36695 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2023-02-24 12:46:56.369238 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000002/logs/progress.log
2023-02-24 12:46:58.952657 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2023-02-24 12:46:58.955136 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000003/logs/progress.log
2023-02-24 12:47:01.556673 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2023-02-24 12:47:01.560147 DEBUG::tools.R/processChunks: done
2023-02-24 12:47:01.56238 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-24 12:47:01.580232 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.counts_exon.tab
2023-02-24 12:47:01.594483 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.counts_exon_disjoint.tab
2023-02-24 12:47:01.604095 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.counts_gene.tab
2023-02-24 12:47:01.611604 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.counts_gene_coding.tab
2023-02-24 12:47:01.619091 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.counts_gene_exonic.tab
2023-02-24 12:47:01.626906 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.counts_intergenic.tab
2023-02-24 12:47:01.639034 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.counts_intron.tab
2023-02-24 12:47:01.642797 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-24 12:47:01.650914 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.summary_counts.tab
2023-02-24 12:47:01.653296 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-24 12:47:02.002333 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-24 12:47:02.003639 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-02-24 12:47:02.086658 INFO::coverage.R/calculateCoverage: starting...
2023-02-24 12:47:02.092083 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:47:06.585365 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:47:06.587714 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000001/logs/progress.log
2023-02-24 12:47:08.791292 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2023-02-24 12:47:08.793614 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000002/logs/progress.log
2023-02-24 12:47:11.004008 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2023-02-24 12:47:11.006424 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/chunks/chunk_000003/logs/progress.log
2023-02-24 12:47:13.221962 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2023-02-24 12:47:13.225565 DEBUG::tools.R/processChunks: done
2023-02-24 12:47:15.069124 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.coverage.RData
2023-02-24 12:47:15.071243 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.coverage.bw
2023-02-24 12:47:15.088413 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.summary_coverage.tab
2023-02-24 12:47:15.090396 INFO::coverage.R/calculateCoverage: done
2023-02-24 12:47:15.09295 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-24 12:47:15.173341 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:47:18.507485 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:47:18.60405 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:47:18.625791 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:47:18.627531 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.raw_variants.RData
2023-02-24 12:47:18.62966 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.filtered_variants.RData
2023-02-24 12:47:18.631397 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-24 12:47:18.632756 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-24 12:47:18.932594 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-24 12:47:19.064277 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/results/test_pe.summary_variants.tab
2023-02-24 12:47:19.066662 INFO::analyzeVariants/analyzeVariants: done
2023-02-24 12:47:19.070815 INFO::Pipeline run successful.
2023-02-24 12:47:19.289509 INFO::mergeLanes.R/doMergeLanes: starting...
2023-02-24 12:47:19.295963 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:47:19.299205 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.adapter_contaminated_1.RData
2023-02-24 12:47:19.303313 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-24 12:47:19.306308 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.adapter_contaminated_2.RData
2023-02-24 12:47:19.322555 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
2023-02-24 12:47:19.327183 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.summary_preprocess.tab
2023-02-24 12:47:19.330386 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:47:19.675603 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-24 12:47:19.686535 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.summary_alignment.tab
2023-02-24 12:47:19.699292 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.summary_analyzed_bamstats.tab
2023-02-24 12:47:19.702429 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-24 12:47:20.00072 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.summary_target_lengths.tab
2023-02-24 12:47:20.067017 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-24 12:47:20.11884 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-24 12:47:20.145974 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.counts_exon.tab
2023-02-24 12:47:20.162688 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.counts_exon_disjoint.tab
2023-02-24 12:47:20.173074 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.counts_gene.tab
2023-02-24 12:47:20.181658 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.counts_gene_coding.tab
2023-02-24 12:47:20.190326 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.counts_gene_exonic.tab
2023-02-24 12:47:20.199442 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.counts_intergenic.tab
2023-02-24 12:47:20.215675 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.counts_intron.tab
2023-02-24 12:47:20.220121 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-24 12:47:20.230047 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.summary_counts.tab
2023-02-24 12:47:20.232779 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-24 12:47:20.509747 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-24 12:47:22.850783 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.coverage.RData
2023-02-24 12:47:22.853847 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.coverage.bw
2023-02-24 12:47:22.869279 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.summary_coverage.tab
2023-02-24 12:47:22.912478 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-24 12:47:22.991875 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:47:26.573558 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:47:26.666307 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:47:26.687113 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:47:26.688862 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.raw_variants.RData
2023-02-24 12:47:26.69093 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.filtered_variants.RData
2023-02-24 12:47:26.692528 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-24 12:47:26.69377 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-24 12:47:26.983588 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-24 12:47:27.111816 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.mergeLanes.59c1b4df6216/merged/results/merged.summary_variants.tab
2023-02-24 12:47:27.114417 INFO::analyzeVariants/analyzeVariants: done
2023-02-24 12:47:27.118093 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
done successfully.
Executing test function test.markDuplicates ... Timing stopped at: 0.001 0 0
Error in DEACTIVATED("Skipped markDuplicates() test") :
Skipped markDuplicates() test
In addition: There were 28 warnings (use warnings() to see them)
done successfully.
Executing test function test.markDuplicates_w_outfile ... Timing stopped at: 0 0 0
Error in DEACTIVATED("Skipped markDuplicates() test") :
Skipped markDuplicates() test
done successfully.
Executing test function test.preprocessReads ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:47:27.517723 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-24 12:47:27.555473 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:47:27.564171 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-02-24 12:47:27.567662 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:47:31.181338 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:47:31.183356 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/chunks/chunk_000001/logs/progress.log
2023-02-24 12:47:33.936852 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-02-24 12:47:34.001749 DEBUG::tools.R/processChunks: done
2023-02-24 12:47:34.004838 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:47:34.007157 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/results/test_pe.adapter_contaminated_1.RData
2023-02-24 12:47:34.00992 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-24 12:47:34.012104 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/results/test_pe.adapter_contaminated_2.RData
2023-02-24 12:47:34.021068 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
2023-02-24 12:47:34.023781 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/results/test_pe.summary_preprocess.tab
2023-02-24 12:47:34.026617 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/bams/processed.aligner_input_1.fastq ...
2023-02-24 12:47:34.031655 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/bams/processed.aligner_input_2.fastq ...
2023-02-24 12:47:34.036092 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/reports/shortReadReport_1 ...
2023-02-24 12:47:35.873875 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.preprocessReads.59c1b407fcadf/reports/shortReadReport_2 ...
2023-02-24 12:47:37.314414 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads.minichunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:47:37.702676 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-24 12:47:37.712478 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:47:37.717882 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-02-24 12:47:37.721437 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:47:41.590431 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:47:41.592494 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/chunks/chunk_000001/logs/progress.log
2023-02-24 12:47:44.416904 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-02-24 12:47:44.41897 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/chunks/chunk_000002/logs/progress.log
2023-02-24 12:47:47.183255 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-02-24 12:47:47.185444 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/chunks/chunk_000003/logs/progress.log
2023-02-24 12:47:49.956325 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-02-24 12:47:50.02798 DEBUG::tools.R/processChunks: done
2023-02-24 12:47:50.032095 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:47:50.03476 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/results/test_pe.adapter_contaminated_1.RData
2023-02-24 12:47:50.038018 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-24 12:47:50.04054 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/results/test_pe.adapter_contaminated_2.RData
2023-02-24 12:47:50.052841 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
2023-02-24 12:47:50.055513 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/results/test_pe.summary_preprocess.tab
2023-02-24 12:47:50.059088 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/bams/processed.aligner_input_1.fastq ...
2023-02-24 12:47:50.065402 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/bams/processed.aligner_input_2.fastq ...
2023-02-24 12:47:50.070733 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/reports/shortReadReport_1 ...
2023-02-24 12:47:51.822012 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.preprocessReads.minichunks.59c1b274e67b0/reports/shortReadReport_2 ...
2023-02-24 12:47:53.261706 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads_single_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:47:53.629289 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-24 12:47:53.654166 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-02-24 12:47:53.657508 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:47:57.419531 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:47:57.421535 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4BoLuA/test.preprocessReads_single_end.59c1b40eccd53/chunks/chunk_000001/logs/progress.log
2023-02-24 12:47:59.921621 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2023-02-24 12:47:59.936117 DEBUG::tools.R/processChunks: done
2023-02-24 12:47:59.939615 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:47:59.942262 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads_single_end.59c1b40eccd53/results/test_se.adapter_contaminated_1.RData
2023-02-24 12:47:59.952333 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
2023-02-24 12:47:59.955262 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.preprocessReads_single_end.59c1b40eccd53/results/test_se.summary_preprocess.tab
2023-02-24 12:47:59.958379 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4BoLuA/test.preprocessReads_single_end.59c1b40eccd53/bams/processed.aligner_input_1.fastq ...
2023-02-24 12:47:59.963969 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4BoLuA/test.preprocessReads_single_end.59c1b40eccd53/reports/shortReadReport_1 ...
2023-02-24 12:48:01.823728 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.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:48:02.660926 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-24 12:48:02.685544 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2023-02-24 12:48:02.709561 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2023-02-24 12:48:02.713176 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:48:06.272843 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:48:06.274927 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-24 12:48:09.288488 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2023-02-24 12:48:09.367383 DEBUG::tools.R/processChunks: done
2023-02-24 12:48:09.370664 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-24 12:48:09.373197 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2023-02-24 12:48:09.375999 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-24 12:48:09.378366 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2023-02-24 12:48:09.387708 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
2023-02-24 12:48:09.390561 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2023-02-24 12:48:09.393506 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2023-02-24 12:48:09.400088 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2023-02-24 12:48:09.406343 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2023-02-24 12:48:11.496466 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2023-02-24 12:48:13.402788 INFO::preprocessReads.R/preprocessReads: done
2023-02-24 12:48:13.487558 INFO::alignReads.R/alignReads: starting alignment...
2023-02-24 12:48:13.49326 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:48:17.044327 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:48:17.046675 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1206:17367:135118" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1304:1838:53573" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2303:2956:116587" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "M" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1206:20028:108227" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1207:19518:143960" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:2207:4065:173048" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2023-02-24 12:48:23.100011 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.101 minutes
2023-02-24 12:48:23.103429 DEBUG::tools.R/processChunks: done
2023-02-24 12:48:23.105336 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2023-02-24 12:48:23.160852 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-24 12:48:23.169307 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2023-02-24 12:48:23.176737 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2023-02-24 12:48:23.179409 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-24 12:48:23.376285 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2023-02-24 12:48:23.436334 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-24 12:48:23.437729 INFO::alignReads.R/alignReads: done
2023-02-24 12:48:23.516857 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-02-24 12:48:23.539376 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:48:26.973441 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:48:26.975702 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-24 12:48:29.639739 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-02-24 12:48:29.643357 DEBUG::tools.R/processChunks: done
2023-02-24 12:48:29.645669 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-24 12:48:29.658625 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2023-02-24 12:48:29.669452 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2023-02-24 12:48:29.677066 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2023-02-24 12:48:29.682461 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2023-02-24 12:48:29.687925 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2023-02-24 12:48:29.693412 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2023-02-24 12:48:29.702024 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2023-02-24 12:48:29.706198 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-24 12:48:29.711326 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2023-02-24 12:48:29.713722 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-24 12:48:29.991965 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-24 12:48:29.993281 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-02-24 12:48:30.073889 INFO::coverage.R/calculateCoverage: starting...
2023-02-24 12:48:30.08031 DEBUG::tools.R/processChunks: starting...
2023-02-24 12:48:34.167234 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-24 12:48:34.169513 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-24 12:48:36.558467 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2023-02-24 12:48:36.56175 DEBUG::tools.R/processChunks: done
2023-02-24 12:48:38.188641 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2023-02-24 12:48:38.190815 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2023-02-24 12:48:38.29482 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2023-02-24 12:48:38.296669 INFO::coverage.R/calculateCoverage: done
2023-02-24 12:48:38.298525 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-24 12:48:38.379766 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-24 12:48:51.301148 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-24 12:48:51.396937 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-24 12:48:51.418011 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-24 12:48:51.419721 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2023-02-24 12:48:51.42344 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2023-02-24 12:48:51.425176 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-24 12:48:51.426458 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-24 12:48:51.716469 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-24 12:48:51.84641 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2023-02-24 12:48:51.848863 INFO::analyzeVariants/analyzeVariants: done
2023-02-24 12:48:51.855506 INFO::Pipeline run successful.
done successfully.
Executing test function test.calculateTargetLength ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4BoLuA/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt
2023-02-24 12:48:52.215129 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4BoLuA/test.calcTargetLengths.59c1b7795480b/results/test_pe.summary_target_lengths.tab
done successfully.
Executing test function test.sclapply ... done successfully.
Executing test function test.tryKeepTraceback ... done successfully.
Executing test function test.truncateReads ... done successfully.
Executing test function test.truncateReads.trim5 ... done successfully.
RUNIT TEST PROTOCOL -- Fri Feb 24 12:49:07 2023
***********************************************
Number of test functions: 61
Number of deactivated test functions: 10
Number of errors: 0
Number of failures: 0
1 Test Suite :
HTSeqGenie unit testing - 61 test functions, 0 errors, 0 failures
Details
***************************
Test Suite: HTSeqGenie unit testing
Test function regexp: ^test.+
Test file regexp: ^runit.+\.[rR]$
Involved directory:
/home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.alignReads.R
test.alignReads: (2 checks) ... OK (29.54 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (18.32 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.67 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.analyzeVariants.R
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (80.02 seconds)
test.wrap.callVariants: (4 checks) ... OK (11.6 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (21.48 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.82 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.19 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.7 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.bamUtils.R
test.isFirstFragment: (5 checks) ... OK (0 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R
test.buildCountsGRangesList: (3 checks) ... OK (36.73 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (34.75 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.calculateCoverage.R
test.computeCoverage: (9 checks) ... OK (0.92 seconds)
test.isSparse: (5 checks) ... OK (0.12 seconds)
test.mergeCoverage: (1 checks) ... OK (1.52 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.31 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.checkConfig.R
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.23 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.config.R
test.checkConfig: (5 checks) ... OK (0.5 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.59 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.17-bioc/R/library/HTSeqGenie/unitTests/runit.detectAdapterContam.R
test.getAdapterSeqs: (5 checks) ... OK (0.05 seconds)
test.isAdapter: (5 checks) ... OK (0.16 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.11 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.detectRRNA.R
test.detectRRNA: (1 checks) ... OK (0.4 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.56 seconds)
test.getRRNAIds: (1 checks) ... OK (0.32 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.26 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.filterQuality.R
test.filterByLength: (2 checks) ... OK (0.08 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.06 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.05 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.gatk.R
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.22 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.17-bioc/R/library/HTSeqGenie/unitTests/runit.io.R
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.3 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.53 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.26 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.29 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.93 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.22 seconds)
test.getObjectFilename: (4 checks) ... OK (0.01 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.29 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.mergeLanes.R
test.mergeLanes: (6 checks) ... OK (66.2 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.picard.R
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.preprocessReads.R
test.preprocessReads: (5 checks) ... OK (10.17 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.95 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.56 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R
test.readRNASeqEnds: (6 checks) ... OK (0.11 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.13 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.reportPipelineQA.R
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.15 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.06 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.runPipeline.R
test.runPipeline: (1 checks) ... OK (49.57 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.targetLengths.R
test.calculateTargetLength: (4 checks) ... OK (0.36 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.tools.R
test.sclapply: (10 checks) ... OK (14.73 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.trimReads.R
test.truncateReads: (7 checks) ... OK (0.07 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.24 seconds)
runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
>
> proc.time()
user system elapsed
313.096 77.921 434.545
HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings
| name | user | system | elapsed | |
| HTSeqGenie | 0.000 | 0.000 | 0.001 | |
| buildGenomicFeaturesFromTxDb | 0.001 | 0.000 | 0.000 | |
| runPipeline | 0 | 0 | 0 | |