| Back to Build/check report for BioC 3.17 |
|
This page was generated on 2023-02-23 01:34:05 -0000 (Thu, 23 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" | 4245 |
| 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/2164 | 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-22 06:37:24 -0000 (Wed, 22 Feb 2023) |
| EndedAt: 2023-02-22 06:55:11 -0000 (Wed, 22 Feb 2023) |
| EllapsedTime: 1067.6 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/Rtmp2Gvsyg/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-22 06:43:55.079741 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-22 06:43:55.089752 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-22 06:43:55.095453 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-22 06:43:55.098351 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:43:58.279153 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:43:58.281271 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/chunks/chunk_000001/logs/progress.log
2023-02-22 06:44:01.150333 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2023-02-22 06:44:01.152308 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/chunks/chunk_000002/logs/progress.log
2023-02-22 06:44:04.045001 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.048 minutes
2023-02-22 06:44:04.04695 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/chunks/chunk_000003/logs/progress.log
2023-02-22 06:44:06.946452 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2023-02-22 06:44:06.990521 DEBUG::tools.R/processChunks: done
2023-02-22 06:44:06.995596 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:44:06.998865 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/results/test_pe.adapter_contaminated_1.RData
2023-02-22 06:44:07.002804 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-22 06:44:07.005306 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/results/test_pe.adapter_contaminated_2.RData
2023-02-22 06:44:07.017962 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-22 06:44:07.021062 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/results/test_pe.summary_preprocess.tab
2023-02-22 06:44:07.025707 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/bams/processed.aligner_input_1.fastq ...
2023-02-22 06:44:07.031317 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/bams/processed.aligner_input_2.fastq ...
2023-02-22 06:44:07.036657 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/reports/shortReadReport_1 ...
2023-02-22 06:44:08.890326 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/reports/shortReadReport_2 ...
2023-02-22 06:44:10.372967 INFO::preprocessReads.R/preprocessReads: done
2023-02-22 06:44:10.427065 INFO::alignReads.R/alignReads: starting alignment...
2023-02-22 06:44:10.434384 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:44:13.654799 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:44:13.657009 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/chunks/chunk_000001/logs/progress.log
2023-02-22 06:44:16.811232 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.053 minutes
2023-02-22 06:44:16.818461 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/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-22 06:44:19.671788 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.048 minutes
2023-02-22 06:44:19.674185 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/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-22 06:44:22.496004 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2023-02-22 06:44:22.49982 DEBUG::tools.R/processChunks: done
2023-02-22 06:44:22.501904 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-22 06:44:22.83012 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-22 06:44:22.842252 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/results/test_pe.summary_alignment.tab
2023-02-22 06:44:22.853099 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/results/test_pe.summary_analyzed_bamstats.tab
2023-02-22 06:44:22.855632 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-22 06:44:23.164196 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.c24285d7a03e7/results/test_pe.summary_target_lengths.tab
2023-02-22 06:44:23.225174 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-22 06:44:23.226551 INFO::alignReads.R/alignReads: done
done successfully.
Executing test function test.alignReads.sparsechunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:44:23.558973 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-22 06:44:23.563513 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-22 06:44:23.651992 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2023-02-22 06:44:23.658992 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-22 06:44:23.663665 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-22 06:44:23.666564 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:44:26.833615 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:44:26.835616 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/chunks/chunk_000001/logs/progress.log
2023-02-22 06:44:29.726662 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2023-02-22 06:44:29.728774 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/chunks/chunk_000002/logs/progress.log
2023-02-22 06:44:32.583906 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.048 minutes
2023-02-22 06:44:32.585881 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/chunks/chunk_000003/logs/progress.log
2023-02-22 06:44:35.561862 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.05 minutes
2023-02-22 06:44:35.563742 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/chunks/chunk_000004/logs/progress.log
2023-02-22 06:44:38.394379 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.047 minutes
2023-02-22 06:44:38.438703 DEBUG::tools.R/processChunks: done
2023-02-22 06:44:38.443731 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:44:38.447228 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/results/test_pe.adapter_contaminated_1.RData
2023-02-22 06:44:38.451611 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-22 06:44:38.454417 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/results/test_pe.adapter_contaminated_2.RData
2023-02-22 06:44:38.468891 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-22 06:44:38.472016 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/results/test_pe.summary_preprocess.tab
2023-02-22 06:44:38.477086 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/bams/processed.aligner_input_1.fastq ...
2023-02-22 06:44:38.483173 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/bams/processed.aligner_input_2.fastq ...
2023-02-22 06:44:38.488086 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/reports/shortReadReport_1 ...
2023-02-22 06:44:40.237556 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.alignReads.sparsechunks.c24282ffcea0c/reports/shortReadReport_2 ...
2023-02-22 06:44:41.642879 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.alignReadsOneSingleEnd ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:44:41.900568 INFO::alignReads.R/alignReadsChunk: running gsnap...
2023-02-22 06:44:41.906261 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/Rtmp2Gvsyg/test.alignReadsOneSingleEnd.c24284ee9cb87/bams/test.alignReads /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2023-02-22 06:44:42.119059 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2023-02-22 06:44:42.247904 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReadsOneSingleEnd.c24284ee9cb87/results/test.alignReads.summary_alignment.tab
2023-02-22 06:44:42.299226 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.alignReadsOneSingleEnd.c24284ee9cb87/results/test.alignReads.summary_analyzed_bamstats.tab
2023-02-22 06:44:42.301271 INFO::alignReads.R/alignReadsChunk: done
done successfully.
Executing test function test.annotateVariants ... Timing stopped at: 0.003 0 0.002
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/Rtmp2Gvsyg/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-22 06:44:42.729298 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.genotype.c24286e3d78d0/results/test_pe.coverage.RData
2023-02-22 06:44:42.731829 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp2Gvsyg/test.genotype.c24286e3d78d0/results/test_pe.coverage.bw
2023-02-22 06:44:42.91176 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.genotype.c24286e3d78d0/results/test_pe.summary_coverage.tab
2023-02-22 06:44:42.914109 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:44:54.681293 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:44:54.79349 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:44:54.816116 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:44:54.818066 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.genotype.c24286e3d78d0/results/test_pe.raw_variants.RData
2023-02-22 06:44:54.821383 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.genotype.c24286e3d78d0/results/test_pe.filtered_variants.RData
2023-02-22 06:44:54.823222 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-22 06:44:54.824805 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-22 06:44:55.376402 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-22 06:44:55.377963 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2023-02-22 06:46:01.380121 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-22 06:46:01.987053 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-22 06:46:01.98829 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/Rtmp2Gvsyg/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-22 06:46:02.608288 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:46:13.852667 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:46:13.952075 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:46:13.973983 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:46:13.9758 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.c2428668db78b/results/test_pe.raw_variants.RData
2023-02-22 06:46:13.979638 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.c2428668db78b/results/test_pe.filtered_variants.RData
2023-02-22 06:46:13.981589 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.filters ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:46:14.19383 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:46:24.833033 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:46:24.907213 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:46:24.929132 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:46:24.93092 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.filters.c2428491036c1/results/test_pe.raw_variants.RData
2023-02-22 06:46:24.934125 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.filters.c2428491036c1/results/test_pe.filtered_variants.RData
2023-02-22 06:46:24.935755 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-22 06:46:24.937339 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:46:35.416523 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:46:35.463239 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:46:35.483774 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:46:35.485488 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.filters.c2428491036c1/results/test_pe.raw_variants.RData
2023-02-22 06:46:35.488755 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.filters.c2428491036c1/results/test_pe.filtered_variants.RData
2023-02-22 06:46:35.491429 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.which ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:46:35.704021 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:46:35.705778 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2023-02-22 06:46:38.174032 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:46:38.268061 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:46:38.289111 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:46:38.290836 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.which.c24283611bc3/results/test_pe.raw_variants.RData
2023-02-22 06:46:38.292842 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.wrap.callVariants.which.c24283611bc3/results/test_pe.filtered_variants.RData
2023-02-22 06:46:38.294468 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.writeVCF.NULL ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:46:38.500521 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-22 06:46:38.502198 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.writeVCF.vcfStat ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:46:38.75758 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-22 06:46:39.059286 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-22 06:47:49.324899 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/bphmaicn/merged/results/bla.coverage.RData
2023-02-22 06:47:49.328011 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp2Gvsyg/bphmaicn/merged/results/bla.coverage.bw
2023-02-22 06:47:49.445194 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/bphmaicn/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.mergeCoverage.sparse ... 2023-02-22 06:47:50.715081 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/yoefzjki/merged/results/bla.coverage.RData
2023-02-22 06:47:50.717059 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp2Gvsyg/yoefzjki/merged/results/bla.coverage.bw
2023-02-22 06:47:50.732169 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/yoefzjki/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.checkConfig.analyzeVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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-22 06:47:52.674692 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-02-22 06:47:52.676265 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp2Gvsyg/test.detectRRNA.c24284ce4ff0f/bams/rRNA_contam/input1.fastq
2023-02-22 06:47:52.681001 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/Rtmp2Gvsyg/test.detectRRNA.c24284ce4ff0f/bams/rRNA_contam/test_se /tmp/Rtmp2Gvsyg/test.detectRRNA.c24284ce4ff0f/bams/rRNA_contam/input1.fastq 2>&1
2023-02-22 06:47:52.83143 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-02-22 06:47:52.832845 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.detectRRNA.paired_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:47:53.081655 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-02-22 06:47:53.083064 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp2Gvsyg/test.detectRRNA.paired_end.c242870563c10/bams/rRNA_contam/input1.fastq
2023-02-22 06:47:53.085381 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp2Gvsyg/test.detectRRNA.paired_end.c242870563c10/bams/rRNA_contam/input2.fastq
2023-02-22 06:47:53.088799 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/Rtmp2Gvsyg/test.detectRRNA.paired_end.c242870563c10/bams/rRNA_contam/test_pe /tmp/Rtmp2Gvsyg/test.detectRRNA.paired_end.c242870563c10/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp2Gvsyg/test.detectRRNA.paired_end.c242870563c10/bams/rRNA_contam/input2.fastq 2>&1
2023-02-22 06:47:53.399048 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-02-22 06:47:53.400636 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.getRRNAIds ... 2023-02-22 06:47:53.430431 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/Rtmp2Gvsyg/test_get_rRNA_idsgksjzdnc/test_pe /tmp/Rtmp2Gvsyg/test_get_rRNA_idsgksjzdnc/1.fastq -a paired /tmp/Rtmp2Gvsyg/test_get_rRNA_idsgksjzdnc/2.fastq 2>&1
done successfully.
Executing test function test.getRRNAIds_random ... 2023-02-22 06:47:53.753015 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/Rtmp2Gvsyg/test_get_rRNAIds_randomrbcqtpmd/test_pe /tmp/Rtmp2Gvsyg/test_get_rRNAIds_randomrbcqtpmd/1.fastq 2>&1
done successfully.
Executing test function test.filterByLength ... 2023-02-22 06:47:53.979498 INFO::filterQuality.R/filterQuality: filterByLength...
2023-02-22 06:47:53.981453 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2023-02-22 06:47:53.982809 INFO::filterQuality.R/filterByLength: done
2023-02-22 06:47:54.049437 INFO::filterQuality.R/filterQuality: filterByLength...
2023-02-22 06:47:54.050727 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2023-02-22 06:47:54.05199 INFO::filterQuality.R/filterByLength: done
done successfully.
Executing test function test.isAboveQualityThresh ... done successfully.
Executing test function test.trimTailsByQuality ... 2023-02-22 06:47:54.126722 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-22 06:47:54.139382 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-22 06:47:54.140904 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-22 06:47:54.14745 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-22 06:47:54.148954 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-22 06:47:54.155467 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-22 06:47:54.156939 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-22 06:47:54.169317 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
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") :
checkGATKJar() test needs gatk.path option set
done successfully.
Executing test function test.excludeVariantsByRegion ... done successfully.
Executing test function test.gatk ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") :
gatk() tests need gatk.path option set
done successfully.
Executing test function test.realignIndels ... Timing stopped at: 0 0 0
Error in DEACTIVATED("test.realignIndels() tests need gatk.path option set") :
test.realignIndels() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK.parallel ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test_zipUp ... done successfully.
Executing test function test.FastQStreamer.getReads.pefq ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:47:54.633968 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-22 06:47:54.637281 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/Rtmp2Gvsyg/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-22 06:47:54.926335 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-22 06:47:55.088745 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-22 06:47:55.092691 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-22 06:47:55.096047 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/Rtmp2Gvsyg/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-22 06:47:55.485681 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/Rtmp2Gvsyg/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-22 06:47:55.725047 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/Rtmp2Gvsyg/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-22 06:47:56.002318 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-22 06:47:56.129925 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-22 06:47:56.13366 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-22 06:47:56.137173 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/Rtmp2Gvsyg/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-22 06:47:56.493238 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-22 06:47:56.56898 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-22 06:47:56.57258 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-22 06:47:56.575893 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/Rtmp2Gvsyg/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/Rtmp2Gvsyg/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-22 06:47:57.76988 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-22 06:47:57.777814 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-22 06:47:57.783242 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-22 06:47:57.786661 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:48:01.174246 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:48:01.176327 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000001/logs/progress.log
2023-02-22 06:48:03.927004 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-02-22 06:48:03.929332 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000002/logs/progress.log
2023-02-22 06:48:06.67603 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-02-22 06:48:06.67809 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000003/logs/progress.log
2023-02-22 06:48:09.413337 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-02-22 06:48:09.484366 DEBUG::tools.R/processChunks: done
2023-02-22 06:48:09.488591 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:48:09.49129 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.adapter_contaminated_1.RData
2023-02-22 06:48:09.494518 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-22 06:48:09.496989 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.adapter_contaminated_2.RData
2023-02-22 06:48:09.508602 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-22 06:48:09.511233 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.summary_preprocess.tab
2023-02-22 06:48:09.514806 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/bams/processed.aligner_input_1.fastq ...
2023-02-22 06:48:09.520571 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/bams/processed.aligner_input_2.fastq ...
2023-02-22 06:48:09.525228 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/reports/shortReadReport_1 ...
2023-02-22 06:48:11.36184 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/reports/shortReadReport_2 ...
2023-02-22 06:48:12.902698 INFO::preprocessReads.R/preprocessReads: done
2023-02-22 06:48:12.97557 INFO::alignReads.R/alignReads: starting alignment...
2023-02-22 06:48:12.981143 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:48:16.65793 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:48:16.660243 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000001/logs/progress.log
2023-02-22 06:48:19.366122 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2023-02-22 06:48:19.368377 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/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-22 06:48:22.093935 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2023-02-22 06:48:22.096057 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/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-22 06:48:24.826168 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2023-02-22 06:48:24.829736 DEBUG::tools.R/processChunks: done
2023-02-22 06:48:24.83169 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-22 06:48:25.115898 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-22 06:48:25.126292 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.summary_alignment.tab
2023-02-22 06:48:25.136253 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.summary_analyzed_bamstats.tab
2023-02-22 06:48:25.138781 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-22 06:48:25.413917 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.summary_target_lengths.tab
2023-02-22 06:48:25.473054 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-22 06:48:25.474389 INFO::alignReads.R/alignReads: done
2023-02-22 06:48:25.550782 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-02-22 06:48:25.576076 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:48:29.024527 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:48:29.026924 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000001/logs/progress.log
2023-02-22 06:48:31.596837 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2023-02-22 06:48:31.599102 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000002/logs/progress.log
2023-02-22 06:48:34.186197 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2023-02-22 06:48:34.188722 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000003/logs/progress.log
2023-02-22 06:48:36.781165 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2023-02-22 06:48:36.784624 DEBUG::tools.R/processChunks: done
2023-02-22 06:48:36.786916 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-22 06:48:36.804957 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.counts_exon.tab
2023-02-22 06:48:36.819179 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.counts_exon_disjoint.tab
2023-02-22 06:48:36.828589 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.counts_gene.tab
2023-02-22 06:48:36.837556 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.counts_gene_coding.tab
2023-02-22 06:48:36.844907 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.counts_gene_exonic.tab
2023-02-22 06:48:36.852535 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.counts_intergenic.tab
2023-02-22 06:48:36.864601 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.counts_intron.tab
2023-02-22 06:48:36.868307 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-22 06:48:36.876225 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.summary_counts.tab
2023-02-22 06:48:36.87852 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-22 06:48:37.227568 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-22 06:48:37.228894 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-02-22 06:48:37.314698 INFO::coverage.R/calculateCoverage: starting...
2023-02-22 06:48:37.320266 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:48:40.728036 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:48:40.730306 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000001/logs/progress.log
2023-02-22 06:48:42.930507 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2023-02-22 06:48:42.932749 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000002/logs/progress.log
2023-02-22 06:48:45.144007 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2023-02-22 06:48:45.146266 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/chunks/chunk_000003/logs/progress.log
2023-02-22 06:48:47.3603 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2023-02-22 06:48:47.364026 DEBUG::tools.R/processChunks: done
2023-02-22 06:48:49.193207 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.coverage.RData
2023-02-22 06:48:49.195377 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.coverage.bw
2023-02-22 06:48:49.211559 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.summary_coverage.tab
2023-02-22 06:48:49.213543 INFO::coverage.R/calculateCoverage: done
2023-02-22 06:48:49.21591 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-22 06:48:49.298937 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:48:52.676281 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:48:52.77083 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:48:52.791462 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:48:52.793127 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.raw_variants.RData
2023-02-22 06:48:52.79514 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.filtered_variants.RData
2023-02-22 06:48:52.796707 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-22 06:48:52.797959 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-22 06:48:53.087457 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-22 06:48:53.217103 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/results/test_pe.summary_variants.tab
2023-02-22 06:48:53.219469 INFO::analyzeVariants/analyzeVariants: done
2023-02-22 06:48:53.223851 INFO::Pipeline run successful.
2023-02-22 06:48:53.435706 INFO::mergeLanes.R/doMergeLanes: starting...
2023-02-22 06:48:53.442363 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:48:53.446005 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.adapter_contaminated_1.RData
2023-02-22 06:48:53.450634 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-22 06:48:53.453821 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.adapter_contaminated_2.RData
2023-02-22 06:48:53.470914 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-22 06:48:53.474564 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.summary_preprocess.tab
2023-02-22 06:48:53.478114 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-22 06:48:53.843872 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-22 06:48:53.856102 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.summary_alignment.tab
2023-02-22 06:48:53.869936 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.summary_analyzed_bamstats.tab
2023-02-22 06:48:53.873252 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-22 06:48:54.184791 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.summary_target_lengths.tab
2023-02-22 06:48:54.254275 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-22 06:48:54.302293 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-22 06:48:54.328629 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.counts_exon.tab
2023-02-22 06:48:54.34488 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.counts_exon_disjoint.tab
2023-02-22 06:48:54.354835 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.counts_gene.tab
2023-02-22 06:48:54.363193 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.counts_gene_coding.tab
2023-02-22 06:48:54.371513 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.counts_gene_exonic.tab
2023-02-22 06:48:54.380227 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.counts_intergenic.tab
2023-02-22 06:48:54.396053 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.counts_intron.tab
2023-02-22 06:48:54.400038 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-22 06:48:54.409041 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.summary_counts.tab
2023-02-22 06:48:54.411644 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-22 06:48:54.680905 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-22 06:48:57.106205 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.coverage.RData
2023-02-22 06:48:57.10964 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.coverage.bw
2023-02-22 06:48:57.125382 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.summary_coverage.tab
2023-02-22 06:48:57.167691 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-22 06:48:57.247386 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:49:00.764914 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:49:00.858447 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:49:00.879403 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:49:00.88113 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.raw_variants.RData
2023-02-22 06:49:00.883173 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.filtered_variants.RData
2023-02-22 06:49:00.884745 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-22 06:49:00.886038 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-22 06:49:01.175652 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-22 06:49:01.301598 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.mergeLanes.c24286095785b/merged/results/merged.summary_variants.tab
2023-02-22 06:49:01.304002 INFO::analyzeVariants/analyzeVariants: done
2023-02-22 06:49:01.307406 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/Rtmp2Gvsyg/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-22 06:49:01.701827 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-22 06:49:01.710405 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-22 06:49:01.716233 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-22 06:49:01.719844 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:49:05.371946 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:49:05.374205 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/chunks/chunk_000001/logs/progress.log
2023-02-22 06:49:08.13807 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-02-22 06:49:08.21483 DEBUG::tools.R/processChunks: done
2023-02-22 06:49:08.218137 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:49:08.220628 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/results/test_pe.adapter_contaminated_1.RData
2023-02-22 06:49:08.223717 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-22 06:49:08.226058 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/results/test_pe.adapter_contaminated_2.RData
2023-02-22 06:49:08.235396 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-22 06:49:08.238166 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/results/test_pe.summary_preprocess.tab
2023-02-22 06:49:08.241073 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/bams/processed.aligner_input_1.fastq ...
2023-02-22 06:49:08.245953 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/bams/processed.aligner_input_2.fastq ...
2023-02-22 06:49:08.250739 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/reports/shortReadReport_1 ...
2023-02-22 06:49:10.104043 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.preprocessReads.c2428454f499e/reports/shortReadReport_2 ...
2023-02-22 06:49:11.572438 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads.minichunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:49:11.947375 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-22 06:49:11.955168 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-22 06:49:11.960316 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-22 06:49:11.963397 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:49:15.464789 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:49:15.46694 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/chunks/chunk_000001/logs/progress.log
2023-02-22 06:49:18.236957 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-02-22 06:49:18.242773 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/chunks/chunk_000002/logs/progress.log
2023-02-22 06:49:21.020612 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-02-22 06:49:21.023288 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/chunks/chunk_000003/logs/progress.log
2023-02-22 06:49:23.813836 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-02-22 06:49:23.882595 DEBUG::tools.R/processChunks: done
2023-02-22 06:49:23.886687 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:49:23.889504 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/results/test_pe.adapter_contaminated_1.RData
2023-02-22 06:49:23.892915 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-22 06:49:23.895604 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/results/test_pe.adapter_contaminated_2.RData
2023-02-22 06:49:23.90767 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-22 06:49:23.910427 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/results/test_pe.summary_preprocess.tab
2023-02-22 06:49:23.914141 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/bams/processed.aligner_input_1.fastq ...
2023-02-22 06:49:23.920007 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/bams/processed.aligner_input_2.fastq ...
2023-02-22 06:49:23.92477 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/reports/shortReadReport_1 ...
2023-02-22 06:49:25.828642 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.preprocessReads.minichunks.c24286e116bda/reports/shortReadReport_2 ...
2023-02-22 06:49:27.378307 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads_single_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:49:27.757377 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-22 06:49:27.786614 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-22 06:49:27.790251 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:49:31.336945 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:49:31.339122 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp2Gvsyg/test.preprocessReads_single_end.c242833ef159/chunks/chunk_000001/logs/progress.log
2023-02-22 06:49:33.841512 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2023-02-22 06:49:33.85543 DEBUG::tools.R/processChunks: done
2023-02-22 06:49:33.858916 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:49:33.861455 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads_single_end.c242833ef159/results/test_se.adapter_contaminated_1.RData
2023-02-22 06:49:33.871494 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-22 06:49:33.874422 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.preprocessReads_single_end.c242833ef159/results/test_se.summary_preprocess.tab
2023-02-22 06:49:33.877457 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp2Gvsyg/test.preprocessReads_single_end.c242833ef159/bams/processed.aligner_input_1.fastq ...
2023-02-22 06:49:33.882749 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp2Gvsyg/test.preprocessReads_single_end.c242833ef159/reports/shortReadReport_1 ...
2023-02-22 06:49:35.662013 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-22 06:49:36.521463 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-22 06:49:36.548574 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-22 06:49:36.555801 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-22 06:49:36.559335 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:49:40.178378 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:49:40.180431 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-22 06:49:43.188808 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2023-02-22 06:49:43.254523 DEBUG::tools.R/processChunks: done
2023-02-22 06:49:43.257897 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-22 06:49:43.260334 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2023-02-22 06:49:43.26303 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-22 06:49:43.265347 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2023-02-22 06:49:43.274687 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-22 06:49:43.277503 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2023-02-22 06:49:43.280463 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2023-02-22 06:49:43.286976 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2023-02-22 06:49:43.293264 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2023-02-22 06:49:45.379288 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2023-02-22 06:49:47.077133 INFO::preprocessReads.R/preprocessReads: done
2023-02-22 06:49:47.153122 INFO::alignReads.R/alignReads: starting alignment...
2023-02-22 06:49:47.159645 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:49:51.442934 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:49:51.445261 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-22 06:49:57.544723 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.102 minutes
2023-02-22 06:49:57.549158 DEBUG::tools.R/processChunks: done
2023-02-22 06:49:57.551413 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2023-02-22 06:49:57.594913 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-22 06:49:57.604098 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2023-02-22 06:49:57.612499 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2023-02-22 06:49:57.615623 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-22 06:49:57.820474 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2023-02-22 06:49:57.883976 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-22 06:49:57.885455 INFO::alignReads.R/alignReads: done
2023-02-22 06:49:57.970165 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-02-22 06:49:57.993787 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:50:01.599794 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:50:01.602198 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-22 06:50:04.264878 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-02-22 06:50:04.26854 DEBUG::tools.R/processChunks: done
2023-02-22 06:50:04.270975 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-22 06:50:04.283938 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2023-02-22 06:50:04.294565 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2023-02-22 06:50:04.302338 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2023-02-22 06:50:04.307747 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2023-02-22 06:50:04.313254 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2023-02-22 06:50:04.31876 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2023-02-22 06:50:04.327201 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2023-02-22 06:50:04.33132 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-22 06:50:04.33644 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2023-02-22 06:50:04.338824 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-22 06:50:04.616277 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-22 06:50:04.617654 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-02-22 06:50:04.699737 INFO::coverage.R/calculateCoverage: starting...
2023-02-22 06:50:04.705292 DEBUG::tools.R/processChunks: starting...
2023-02-22 06:50:08.139847 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-22 06:50:08.142189 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-22 06:50:10.540921 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2023-02-22 06:50:10.544514 DEBUG::tools.R/processChunks: done
2023-02-22 06:50:12.33092 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2023-02-22 06:50:12.333119 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2023-02-22 06:50:12.44683 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2023-02-22 06:50:12.448593 INFO::coverage.R/calculateCoverage: done
2023-02-22 06:50:12.450369 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-22 06:50:12.543788 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-22 06:50:24.954729 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-22 06:50:25.049708 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-22 06:50:25.070598 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-22 06:50:25.072236 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2023-02-22 06:50:25.075871 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2023-02-22 06:50:25.077602 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-22 06:50:25.078865 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-22 06:50:25.375928 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-22 06:50:25.508289 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2023-02-22 06:50:25.511123 INFO::analyzeVariants/analyzeVariants: done
2023-02-22 06:50:25.519103 INFO::Pipeline run successful.
done successfully.
Executing test function test.calculateTargetLength ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp2Gvsyg/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-22 06:50:25.864978 INFO::io.R/saveWithID: saving file= /tmp/Rtmp2Gvsyg/test.calcTargetLengths.c2428593ef815/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 -- Wed Feb 22 06:50:41 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.75 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (18.41 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.65 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.08 seconds)
test.wrap.callVariants: (4 checks) ... OK (11.59 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (21.51 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.8 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.21 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.69 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 (35.71 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (31.85 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.calculateCoverage.R
test.computeCoverage: (9 checks) ... OK (0.94 seconds)
test.isSparse: (5 checks) ... OK (0.12 seconds)
test.mergeCoverage: (1 checks) ... OK (1.62 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.24 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.6 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.57 seconds)
test.getRRNAIds: (1 checks) ... OK (0.32 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.25 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.06 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.31 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.54 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.25 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.28 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.93 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.23 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 (64.08 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.23 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.81 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.28 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R
test.readRNASeqEnds: (6 checks) ... OK (0.12 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.12 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.39 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.targetLengths.R
test.calculateTargetLength: (4 checks) ... OK (0.34 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.tools.R
test.sclapply: (10 checks) ... OK (15.35 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.23 seconds)
runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
>
> proc.time()
user system elapsed
308.295 77.262 428.925
HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings
| name | user | system | elapsed | |
| HTSeqGenie | 0 | 0 | 0 | |
| buildGenomicFeaturesFromTxDb | 0.001 | 0.000 | 0.000 | |
| runPipeline | 0 | 0 | 0 | |