| Back to Build/check report for BioC 3.17: simplified long |
|
This page was generated on 2023-03-01 07:38:42 -0000 (Wed, 01 Mar 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" | 4266 |
| 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 917/2171 | 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-28 05:51:36 -0000 (Tue, 28 Feb 2023) |
| EndedAt: 2023-02-28 06:09:14 -0000 (Tue, 28 Feb 2023) |
| EllapsedTime: 1058.4 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/RtmpOGzUwb/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-28 05:58:04.59508 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-28 05:58:04.607161 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-28 05:58:04.613 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-28 05:58:04.616216 DEBUG::tools.R/processChunks: starting...
2023-02-28 05:58:07.766086 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 05:58:07.768212 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/chunks/chunk_000001/logs/progress.log
2023-02-28 05:58:10.682778 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2023-02-28 05:58:10.686518 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/chunks/chunk_000002/logs/progress.log
2023-02-28 05:58:13.568037 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.048 minutes
2023-02-28 05:58:13.570101 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/chunks/chunk_000003/logs/progress.log
2023-02-28 05:58:16.468363 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2023-02-28 05:58:16.510171 DEBUG::tools.R/processChunks: done
2023-02-28 05:58:16.515192 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 05:58:16.518381 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/results/test_pe.adapter_contaminated_1.RData
2023-02-28 05:58:16.522264 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-28 05:58:16.524764 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/results/test_pe.adapter_contaminated_2.RData
2023-02-28 05:58:16.537326 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-28 05:58:16.540425 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/results/test_pe.summary_preprocess.tab
2023-02-28 05:58:16.544872 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/bams/processed.aligner_input_1.fastq ...
2023-02-28 05:58:16.550498 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/bams/processed.aligner_input_2.fastq ...
2023-02-28 05:58:16.555252 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/reports/shortReadReport_1 ...
2023-02-28 05:58:18.331869 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/reports/shortReadReport_2 ...
2023-02-28 05:58:19.735396 INFO::preprocessReads.R/preprocessReads: done
2023-02-28 05:58:19.788065 INFO::alignReads.R/alignReads: starting alignment...
2023-02-28 05:58:19.794862 DEBUG::tools.R/processChunks: starting...
2023-02-28 05:58:22.98523 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 05:58:22.987856 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/chunks/chunk_000001/logs/progress.log
2023-02-28 05:58:26.089513 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2023-02-28 05:58:26.098497 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/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-28 05:58:28.928336 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-02-28 05:58:28.930547 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/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-28 05:58:31.717677 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-02-28 05:58:31.721573 DEBUG::tools.R/processChunks: done
2023-02-28 05:58:31.72382 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-28 05:58:32.062984 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-28 05:58:32.07533 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/results/test_pe.summary_alignment.tab
2023-02-28 05:58:32.08652 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/results/test_pe.summary_analyzed_bamstats.tab
2023-02-28 05:58:32.089139 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-28 05:58:32.399397 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.a7c5ed713bde/results/test_pe.summary_target_lengths.tab
2023-02-28 05:58:32.4637 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-28 05:58:32.465147 INFO::alignReads.R/alignReads: done
done successfully.
Executing test function test.alignReads.sparsechunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 05:58:32.801433 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-28 05:58:32.805744 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-28 05:58:32.952107 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2023-02-28 05:58:32.959333 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-28 05:58:32.964159 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-28 05:58:32.96699 DEBUG::tools.R/processChunks: starting...
2023-02-28 05:58:36.469751 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 05:58:36.471769 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/chunks/chunk_000001/logs/progress.log
2023-02-28 05:58:39.314943 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-02-28 05:58:39.317117 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/chunks/chunk_000002/logs/progress.log
2023-02-28 05:58:42.141208 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-02-28 05:58:42.143466 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/chunks/chunk_000003/logs/progress.log
2023-02-28 05:58:45.096022 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2023-02-28 05:58:45.09797 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/chunks/chunk_000004/logs/progress.log
2023-02-28 05:58:47.922287 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.047 minutes
2023-02-28 05:58:47.96715 DEBUG::tools.R/processChunks: done
2023-02-28 05:58:47.97221 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 05:58:47.975889 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/results/test_pe.adapter_contaminated_1.RData
2023-02-28 05:58:47.980565 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-28 05:58:47.983536 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/results/test_pe.adapter_contaminated_2.RData
2023-02-28 05:58:47.999135 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-28 05:58:48.002426 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/results/test_pe.summary_preprocess.tab
2023-02-28 05:58:48.007699 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/bams/processed.aligner_input_1.fastq ...
2023-02-28 05:58:48.014721 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/bams/processed.aligner_input_2.fastq ...
2023-02-28 05:58:48.019619 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/reports/shortReadReport_1 ...
2023-02-28 05:58:49.821914 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.alignReads.sparsechunks.a7c5e4cbe7e49/reports/shortReadReport_2 ...
2023-02-28 05:58:51.266522 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.alignReadsOneSingleEnd ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 05:58:51.518769 INFO::alignReads.R/alignReadsChunk: running gsnap...
2023-02-28 05:58:51.524696 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/RtmpOGzUwb/test.alignReadsOneSingleEnd.a7c5e6391b3db/bams/test.alignReads /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2023-02-28 05:58:51.733502 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2023-02-28 05:58:51.870791 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReadsOneSingleEnd.a7c5e6391b3db/results/test.alignReads.summary_alignment.tab
2023-02-28 05:58:51.923925 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.alignReadsOneSingleEnd.a7c5e6391b3db/results/test.alignReads.summary_analyzed_bamstats.tab
2023-02-28 05:58:51.926046 INFO::alignReads.R/alignReadsChunk: done
done successfully.
Executing test function test.annotateVariants ... Timing stopped at: 0.001 0.002 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/RtmpOGzUwb/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-28 05:58:52.388033 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.genotype.a7c5e51314995/results/test_pe.coverage.RData
2023-02-28 05:58:52.390807 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOGzUwb/test.genotype.a7c5e51314995/results/test_pe.coverage.bw
2023-02-28 05:58:52.585679 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.genotype.a7c5e51314995/results/test_pe.summary_coverage.tab
2023-02-28 05:58:52.58826 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 05:59:04.427405 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 05:59:04.539326 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 05:59:04.561634 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 05:59:04.563523 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.genotype.a7c5e51314995/results/test_pe.raw_variants.RData
2023-02-28 05:59:04.566745 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.genotype.a7c5e51314995/results/test_pe.filtered_variants.RData
2023-02-28 05:59:04.568511 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-28 05:59:04.570053 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-28 05:59:05.11182 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-28 05:59:05.113296 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2023-02-28 06:00:12.3982 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-28 06:00:12.997926 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-28 06:00:12.999257 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/RtmpOGzUwb/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-28 06:00:13.635587 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 06:00:24.861592 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 06:00:24.967202 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 06:00:24.989164 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 06:00:24.990957 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.a7c5e1c2c047d/results/test_pe.raw_variants.RData
2023-02-28 06:00:24.994078 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.a7c5e1c2c047d/results/test_pe.filtered_variants.RData
2023-02-28 06:00:24.99586 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.filters ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:00:25.187747 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 06:00:36.276026 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 06:00:36.349427 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 06:00:36.37108 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 06:00:36.37283 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.filters.a7c5e55c871/results/test_pe.raw_variants.RData
2023-02-28 06:00:36.376127 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.filters.a7c5e55c871/results/test_pe.filtered_variants.RData
2023-02-28 06:00:36.377894 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-28 06:00:36.379563 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 06:00:47.495871 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 06:00:47.543441 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 06:00:47.564608 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 06:00:47.566293 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.filters.a7c5e55c871/results/test_pe.raw_variants.RData
2023-02-28 06:00:47.569639 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.filters.a7c5e55c871/results/test_pe.filtered_variants.RData
2023-02-28 06:00:47.572452 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.which ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:00:47.784455 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 06:00:47.786226 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2023-02-28 06:00:50.204701 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 06:00:50.297666 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 06:00:50.318235 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 06:00:50.319937 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.which.a7c5e5ed832d8/results/test_pe.raw_variants.RData
2023-02-28 06:00:50.321961 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.wrap.callVariants.which.a7c5e5ed832d8/results/test_pe.filtered_variants.RData
2023-02-28 06:00:50.323611 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.writeVCF.NULL ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:00:50.513337 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-28 06:00:50.51491 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.writeVCF.vcfStat ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:00:50.765671 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-28 06:00:51.063157 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-28 06:02:05.638521 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/olpgmhru/merged/results/bla.coverage.RData
2023-02-28 06:02:05.641761 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOGzUwb/olpgmhru/merged/results/bla.coverage.bw
2023-02-28 06:02:05.757576 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/olpgmhru/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.mergeCoverage.sparse ... 2023-02-28 06:02:07.003891 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/icpfqwxj/merged/results/bla.coverage.RData
2023-02-28 06:02:07.005881 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOGzUwb/icpfqwxj/merged/results/bla.coverage.bw
2023-02-28 06:02:07.02129 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/icpfqwxj/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.checkConfig.analyzeVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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/RtmpOGzUwb/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-28 06:02:09.006346 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-02-28 06:02:09.008022 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpOGzUwb/test.detectRRNA.a7c5e1137e646/bams/rRNA_contam/input1.fastq
2023-02-28 06:02:09.013013 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/RtmpOGzUwb/test.detectRRNA.a7c5e1137e646/bams/rRNA_contam/test_se /tmp/RtmpOGzUwb/test.detectRRNA.a7c5e1137e646/bams/rRNA_contam/input1.fastq 2>&1
2023-02-28 06:02:09.174857 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-02-28 06:02:09.176391 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.detectRRNA.paired_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:02:09.430084 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-02-28 06:02:09.431527 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpOGzUwb/test.detectRRNA.paired_end.a7c5e4e15c8d5/bams/rRNA_contam/input1.fastq
2023-02-28 06:02:09.433803 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpOGzUwb/test.detectRRNA.paired_end.a7c5e4e15c8d5/bams/rRNA_contam/input2.fastq
2023-02-28 06:02:09.437206 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/RtmpOGzUwb/test.detectRRNA.paired_end.a7c5e4e15c8d5/bams/rRNA_contam/test_pe /tmp/RtmpOGzUwb/test.detectRRNA.paired_end.a7c5e4e15c8d5/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpOGzUwb/test.detectRRNA.paired_end.a7c5e4e15c8d5/bams/rRNA_contam/input2.fastq 2>&1
2023-02-28 06:02:09.74121 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-02-28 06:02:09.742633 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.getRRNAIds ... 2023-02-28 06:02:09.771649 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/RtmpOGzUwb/test_get_rRNA_idsredhwtja/test_pe /tmp/RtmpOGzUwb/test_get_rRNA_idsredhwtja/1.fastq -a paired /tmp/RtmpOGzUwb/test_get_rRNA_idsredhwtja/2.fastq 2>&1
done successfully.
Executing test function test.getRRNAIds_random ... 2023-02-28 06:02:10.107306 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/RtmpOGzUwb/test_get_rRNAIds_randomjvmncsrb/test_pe /tmp/RtmpOGzUwb/test_get_rRNAIds_randomjvmncsrb/1.fastq 2>&1
done successfully.
Executing test function test.filterByLength ... 2023-02-28 06:02:10.345459 INFO::filterQuality.R/filterQuality: filterByLength...
2023-02-28 06:02:10.347469 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2023-02-28 06:02:10.34877 INFO::filterQuality.R/filterByLength: done
2023-02-28 06:02:10.416223 INFO::filterQuality.R/filterQuality: filterByLength...
2023-02-28 06:02:10.417524 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2023-02-28 06:02:10.418827 INFO::filterQuality.R/filterByLength: done
done successfully.
Executing test function test.isAboveQualityThresh ... done successfully.
Executing test function test.trimTailsByQuality ... 2023-02-28 06:02:10.493219 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-28 06:02:10.505937 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-28 06:02:10.507513 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-28 06:02:10.514042 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-28 06:02:10.515594 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-28 06:02:10.52206 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-02-28 06:02:10.523575 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-02-28 06:02:10.530014 INFO::preprocessReads.R/preprocessReadsChunk: done
done successfully.
Executing test function test.callVariantsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
In addition: There were 50 or more warnings (use warnings() to see the first 50)
done successfully.
Executing test function test.callVariantsGATK.withFiltering ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
done successfully.
Executing test function test.checkGATKJar ... Timing stopped at: 0 0 0.001
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") :
checkGATKJar() test needs gatk.path option set
done successfully.
Executing test function test.excludeVariantsByRegion ... done successfully.
Executing test function test.gatk ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") :
gatk() tests need gatk.path option set
done successfully.
Executing test function test.realignIndels ... Timing stopped at: 0.001 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.001
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/RtmpOGzUwb/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-28 06:02:10.983337 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-28 06:02:10.986676 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/RtmpOGzUwb/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-28 06:02:11.288958 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-28 06:02:11.463547 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-28 06:02:11.46753 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-28 06:02:11.470945 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/RtmpOGzUwb/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-28 06:02:11.866964 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/RtmpOGzUwb/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-28 06:02:12.109859 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/RtmpOGzUwb/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-28 06:02:12.408924 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-28 06:02:12.546447 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-28 06:02:12.550268 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-28 06:02:12.553767 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/RtmpOGzUwb/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-28 06:02:12.923427 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-28 06:02:13.0033 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-02-28 06:02:13.006888 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-28 06:02:13.010274 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/RtmpOGzUwb/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/RtmpOGzUwb/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-28 06:02:14.204652 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-28 06:02:14.212527 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-28 06:02:14.217791 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-28 06:02:14.2211 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:02:17.656448 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:02:17.658475 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000001/logs/progress.log
2023-02-28 06:02:20.468452 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-02-28 06:02:20.470448 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000002/logs/progress.log
2023-02-28 06:02:23.297275 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-02-28 06:02:23.299387 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000003/logs/progress.log
2023-02-28 06:02:26.097952 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2023-02-28 06:02:26.171964 DEBUG::tools.R/processChunks: done
2023-02-28 06:02:26.176098 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 06:02:26.178826 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.adapter_contaminated_1.RData
2023-02-28 06:02:26.182084 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-28 06:02:26.184632 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.adapter_contaminated_2.RData
2023-02-28 06:02:26.196939 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-28 06:02:26.199725 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.summary_preprocess.tab
2023-02-28 06:02:26.203402 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/bams/processed.aligner_input_1.fastq ...
2023-02-28 06:02:26.209054 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/bams/processed.aligner_input_2.fastq ...
2023-02-28 06:02:26.213951 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/reports/shortReadReport_1 ...
2023-02-28 06:02:27.99073 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/reports/shortReadReport_2 ...
2023-02-28 06:02:29.422497 INFO::preprocessReads.R/preprocessReads: done
2023-02-28 06:02:29.495322 INFO::alignReads.R/alignReads: starting alignment...
2023-02-28 06:02:29.500734 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:02:34.208547 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:02:34.210794 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000001/logs/progress.log
2023-02-28 06:02:36.951943 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-02-28 06:02:36.95427 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/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-28 06:02:39.675201 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2023-02-28 06:02:39.677605 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/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-28 06:02:42.380572 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2023-02-28 06:02:42.384029 DEBUG::tools.R/processChunks: done
2023-02-28 06:02:42.386073 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-28 06:02:42.680425 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-28 06:02:42.691658 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.summary_alignment.tab
2023-02-28 06:02:42.702365 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.summary_analyzed_bamstats.tab
2023-02-28 06:02:42.705175 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-28 06:02:42.992309 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.summary_target_lengths.tab
2023-02-28 06:02:43.05281 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-28 06:02:43.054204 INFO::alignReads.R/alignReads: done
2023-02-28 06:02:43.126637 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-02-28 06:02:43.150722 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:02:47.50316 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:02:47.505511 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000001/logs/progress.log
2023-02-28 06:02:50.082585 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2023-02-28 06:02:50.084976 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000002/logs/progress.log
2023-02-28 06:02:52.692118 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2023-02-28 06:02:52.694507 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000003/logs/progress.log
2023-02-28 06:02:55.258453 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2023-02-28 06:02:55.261767 DEBUG::tools.R/processChunks: done
2023-02-28 06:02:55.263977 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-28 06:02:55.281485 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.counts_exon.tab
2023-02-28 06:02:55.29565 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.counts_exon_disjoint.tab
2023-02-28 06:02:55.305188 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.counts_gene.tab
2023-02-28 06:02:55.312779 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.counts_gene_coding.tab
2023-02-28 06:02:55.32028 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.counts_gene_exonic.tab
2023-02-28 06:02:55.32788 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.counts_intergenic.tab
2023-02-28 06:02:55.339601 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.counts_intron.tab
2023-02-28 06:02:55.343608 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-28 06:02:55.351686 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.summary_counts.tab
2023-02-28 06:02:55.354016 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-28 06:02:55.700415 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-28 06:02:55.701649 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-02-28 06:02:55.775618 INFO::coverage.R/calculateCoverage: starting...
2023-02-28 06:02:55.780859 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:02:59.169812 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:02:59.17208 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000001/logs/progress.log
2023-02-28 06:03:01.374345 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2023-02-28 06:03:01.376647 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000002/logs/progress.log
2023-02-28 06:03:03.586995 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2023-02-28 06:03:03.589607 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/chunks/chunk_000003/logs/progress.log
2023-02-28 06:03:05.797264 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2023-02-28 06:03:05.800845 DEBUG::tools.R/processChunks: done
2023-02-28 06:03:07.482448 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.coverage.RData
2023-02-28 06:03:07.484412 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.coverage.bw
2023-02-28 06:03:07.501338 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.summary_coverage.tab
2023-02-28 06:03:07.503331 INFO::coverage.R/calculateCoverage: done
2023-02-28 06:03:07.505987 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-28 06:03:07.578982 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 06:03:10.898008 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 06:03:10.995333 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 06:03:11.017106 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 06:03:11.018874 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.raw_variants.RData
2023-02-28 06:03:11.021039 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.filtered_variants.RData
2023-02-28 06:03:11.022775 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-28 06:03:11.024154 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-28 06:03:11.323547 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-28 06:03:11.456095 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/results/test_pe.summary_variants.tab
2023-02-28 06:03:11.458563 INFO::analyzeVariants/analyzeVariants: done
2023-02-28 06:03:11.462688 INFO::Pipeline run successful.
2023-02-28 06:03:11.667867 INFO::mergeLanes.R/doMergeLanes: starting...
2023-02-28 06:03:11.673683 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 06:03:11.676845 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.adapter_contaminated_1.RData
2023-02-28 06:03:11.680838 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-28 06:03:11.683722 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.adapter_contaminated_2.RData
2023-02-28 06:03:11.698847 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-28 06:03:11.702228 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.summary_preprocess.tab
2023-02-28 06:03:11.705271 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-28 06:03:12.049647 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-28 06:03:12.060152 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.summary_alignment.tab
2023-02-28 06:03:12.072347 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.summary_analyzed_bamstats.tab
2023-02-28 06:03:12.075582 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-28 06:03:12.373886 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.summary_target_lengths.tab
2023-02-28 06:03:12.439864 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-28 06:03:12.48164 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-28 06:03:12.510874 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.counts_exon.tab
2023-02-28 06:03:12.528915 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.counts_exon_disjoint.tab
2023-02-28 06:03:12.540663 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.counts_gene.tab
2023-02-28 06:03:12.550607 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.counts_gene_coding.tab
2023-02-28 06:03:12.560794 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.counts_gene_exonic.tab
2023-02-28 06:03:12.571388 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.counts_intergenic.tab
2023-02-28 06:03:12.589044 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.counts_intron.tab
2023-02-28 06:03:12.593544 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-28 06:03:12.604585 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.summary_counts.tab
2023-02-28 06:03:12.607664 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-28 06:03:12.892702 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-28 06:03:15.142243 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.coverage.RData
2023-02-28 06:03:15.145243 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.coverage.bw
2023-02-28 06:03:15.160269 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.summary_coverage.tab
2023-02-28 06:03:15.196604 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-28 06:03:15.275112 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 06:03:18.874821 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 06:03:18.974279 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 06:03:18.996345 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 06:03:18.998168 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.raw_variants.RData
2023-02-28 06:03:19.000408 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.filtered_variants.RData
2023-02-28 06:03:19.002115 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-28 06:03:19.003503 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-28 06:03:19.314051 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-28 06:03:19.450185 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.mergeLanes.a7c5e2bfc0052/merged/results/merged.summary_variants.tab
2023-02-28 06:03:19.452798 INFO::analyzeVariants/analyzeVariants: done
2023-02-28 06:03:19.456232 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
done successfully.
Executing test function test.markDuplicates ... Timing stopped at: 0 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/RtmpOGzUwb/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-28 06:03:19.847646 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-28 06:03:19.873447 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-28 06:03:19.895666 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-28 06:03:19.898989 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:03:23.320165 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:03:23.322139 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/chunks/chunk_000001/logs/progress.log
2023-02-28 06:03:26.126158 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-02-28 06:03:26.190612 DEBUG::tools.R/processChunks: done
2023-02-28 06:03:26.193746 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 06:03:26.196229 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/results/test_pe.adapter_contaminated_1.RData
2023-02-28 06:03:26.198884 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-28 06:03:26.201227 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/results/test_pe.adapter_contaminated_2.RData
2023-02-28 06:03:26.21022 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-28 06:03:26.21301 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/results/test_pe.summary_preprocess.tab
2023-02-28 06:03:26.215904 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/bams/processed.aligner_input_1.fastq ...
2023-02-28 06:03:26.220992 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/bams/processed.aligner_input_2.fastq ...
2023-02-28 06:03:26.225801 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/reports/shortReadReport_1 ...
2023-02-28 06:03:28.128817 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.preprocessReads.a7c5e2d5fbf70/reports/shortReadReport_2 ...
2023-02-28 06:03:29.653889 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads.minichunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:03:30.004145 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-28 06:03:30.011836 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-28 06:03:30.016912 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-28 06:03:30.020041 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:03:33.415194 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:03:33.417345 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/chunks/chunk_000001/logs/progress.log
2023-02-28 06:03:36.216271 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-02-28 06:03:36.218428 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/chunks/chunk_000002/logs/progress.log
2023-02-28 06:03:39.008314 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-02-28 06:03:39.010678 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/chunks/chunk_000003/logs/progress.log
2023-02-28 06:03:41.784707 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-02-28 06:03:41.86058 DEBUG::tools.R/processChunks: done
2023-02-28 06:03:41.865203 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 06:03:41.868207 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/results/test_pe.adapter_contaminated_1.RData
2023-02-28 06:03:41.87195 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-28 06:03:41.874876 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/results/test_pe.adapter_contaminated_2.RData
2023-02-28 06:03:41.887975 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-28 06:03:41.890906 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/results/test_pe.summary_preprocess.tab
2023-02-28 06:03:41.894884 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/bams/processed.aligner_input_1.fastq ...
2023-02-28 06:03:41.901192 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/bams/processed.aligner_input_2.fastq ...
2023-02-28 06:03:41.906208 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/reports/shortReadReport_1 ...
2023-02-28 06:03:43.849647 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.preprocessReads.minichunks.a7c5e23582cdc/reports/shortReadReport_2 ...
2023-02-28 06:03:45.359834 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads_single_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:03:45.710821 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-28 06:03:45.735773 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-28 06:03:45.739064 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:03:49.168217 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:03:49.170234 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOGzUwb/test.preprocessReads_single_end.a7c5e5e22df43/chunks/chunk_000001/logs/progress.log
2023-02-28 06:03:51.699889 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2023-02-28 06:03:51.714379 DEBUG::tools.R/processChunks: done
2023-02-28 06:03:51.717744 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 06:03:51.720313 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads_single_end.a7c5e5e22df43/results/test_se.adapter_contaminated_1.RData
2023-02-28 06:03:51.73009 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-28 06:03:51.732995 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.preprocessReads_single_end.a7c5e5e22df43/results/test_se.summary_preprocess.tab
2023-02-28 06:03:51.736018 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOGzUwb/test.preprocessReads_single_end.a7c5e5e22df43/bams/processed.aligner_input_1.fastq ...
2023-02-28 06:03:51.74115 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOGzUwb/test.preprocessReads_single_end.a7c5e5e22df43/reports/shortReadReport_1 ...
2023-02-28 06:03:53.569266 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-28 06:03:54.386474 INFO::preprocessReads.R/preprocessReads: starting...
2023-02-28 06:03:54.4102 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-28 06:03:54.417063 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-28 06:03:54.420157 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:03:58.076376 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:03:58.078587 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-28 06:04:01.067902 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2023-02-28 06:04:01.140086 DEBUG::tools.R/processChunks: done
2023-02-28 06:04:01.143323 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-02-28 06:04:01.14572 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2023-02-28 06:04:01.148301 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-02-28 06:04:01.150542 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2023-02-28 06:04:01.159506 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-28 06:04:01.162225 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2023-02-28 06:04:01.164971 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2023-02-28 06:04:01.171279 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2023-02-28 06:04:01.177096 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2023-02-28 06:04:03.209771 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2023-02-28 06:04:04.915704 INFO::preprocessReads.R/preprocessReads: done
2023-02-28 06:04:04.986098 INFO::alignReads.R/alignReads: starting alignment...
2023-02-28 06:04:04.992022 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:04:09.262252 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:04:09.26471 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-28 06:04:15.097471 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.097 minutes
2023-02-28 06:04:15.101167 DEBUG::tools.R/processChunks: done
2023-02-28 06:04:15.103394 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2023-02-28 06:04:15.144881 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-02-28 06:04:15.154227 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2023-02-28 06:04:15.162715 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2023-02-28 06:04:15.165801 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-02-28 06:04:15.366301 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2023-02-28 06:04:15.426447 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-02-28 06:04:15.427818 INFO::alignReads.R/alignReads: done
2023-02-28 06:04:15.504898 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-02-28 06:04:15.527957 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:04:18.930036 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:04:18.932249 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-28 06:04:21.577271 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-02-28 06:04:21.580633 DEBUG::tools.R/processChunks: done
2023-02-28 06:04:21.582862 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-02-28 06:04:21.595333 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2023-02-28 06:04:21.605624 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2023-02-28 06:04:21.613305 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2023-02-28 06:04:21.618774 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2023-02-28 06:04:21.624221 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2023-02-28 06:04:21.629601 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2023-02-28 06:04:21.637702 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2023-02-28 06:04:21.641824 INFO::countGenomicFeatures.R/mergeCounts: done
2023-02-28 06:04:21.646791 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2023-02-28 06:04:21.649124 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-02-28 06:04:21.915981 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-02-28 06:04:21.91725 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-02-28 06:04:21.992709 INFO::coverage.R/calculateCoverage: starting...
2023-02-28 06:04:21.997864 DEBUG::tools.R/processChunks: starting...
2023-02-28 06:04:25.393706 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-02-28 06:04:25.3959 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-02-28 06:04:27.792337 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2023-02-28 06:04:27.796087 DEBUG::tools.R/processChunks: done
2023-02-28 06:04:29.519513 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2023-02-28 06:04:29.521931 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2023-02-28 06:04:29.633136 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2023-02-28 06:04:29.647543 INFO::coverage.R/calculateCoverage: done
2023-02-28 06:04:29.649508 INFO::analyzeVariants/analyzeVariants: starting ...
2023-02-28 06:04:29.729192 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-02-28 06:04:42.390666 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-02-28 06:04:42.488109 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-02-28 06:04:42.509739 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-02-28 06:04:42.511506 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2023-02-28 06:04:42.515188 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2023-02-28 06:04:42.517021 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-02-28 06:04:42.518327 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-02-28 06:04:42.818285 INFO::analyzeVariants.R/writeVCF: ...done
2023-02-28 06:04:42.94875 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2023-02-28 06:04:42.951305 INFO::analyzeVariants/analyzeVariants: done
2023-02-28 06:04:42.95808 INFO::Pipeline run successful.
done successfully.
Executing test function test.calculateTargetLength ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOGzUwb/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-28 06:04:43.293428 INFO::io.R/saveWithID: saving file= /tmp/RtmpOGzUwb/test.calcTargetLengths.a7c5e5291545f/results/test_pe.summary_target_lengths.tab
done successfully.
Executing test function test.sclapply ... done successfully.
Executing test function test.tryKeepTraceback ... done successfully.
Executing test function test.truncateReads ... done successfully.
Executing test function test.truncateReads.trim5 ... done successfully.
RUNIT TEST PROTOCOL -- Tue Feb 28 06:04:57 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.57 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (18.79 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.66 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 (81.51 seconds)
test.wrap.callVariants: (4 checks) ... OK (11.55 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (22.57 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.75 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.19 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.68 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 (37.17 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (34.65 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.calculateCoverage.R
test.computeCoverage: (9 checks) ... OK (1.05 seconds)
test.isSparse: (5 checks) ... OK (0.12 seconds)
test.mergeCoverage: (1 checks) ... OK (1.56 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.29 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.checkConfig.R
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.23 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.config.R
test.checkConfig: (5 checks) ... OK (0.52 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.62 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.15 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.42 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.57 seconds)
test.getRRNAIds: (1 checks) ... OK (0.33 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.26 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.filterQuality.R
test.filterByLength: (2 checks) ... OK (0.08 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.06 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.05 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.gatk.R
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.21 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.56 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.25 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.3 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.97 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.24 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 (65.78 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.picard.R
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.preprocessReads.R
test.preprocessReads: (5 checks) ... OK (10.17 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.71 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.21 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R
test.readRNASeqEnds: (6 checks) ... OK (0.11 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.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.16 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 (48.93 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 (13.47 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.08 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.24 seconds)
runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
>
> proc.time()
user system elapsed
315.251 75.366 434.463
HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings
| name | user | system | elapsed | |
| HTSeqGenie | 0.001 | 0.000 | 0.000 | |
| buildGenomicFeaturesFromTxDb | 0 | 0 | 0 | |
| runPipeline | 0.000 | 0.000 | 0.001 | |