| Back to Build/check report for BioC 3.17: simplified long |
|
This page was generated on 2023-03-27 05:50:36 -0000 (Mon, 27 Mar 2023).
| Hostname | OS | Arch (*) | R version | Installed pkgs |
|---|---|---|---|---|
| kunpeng1 | Linux (Ubuntu 22.04.1 LTS) | aarch64 | R Under development (unstable) (2023-03-12 r83975) -- "Unsuffered Consequences" | 6083 |
| 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 937/2195 | 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/site-library --timings HTSeqGenie_4.29.1.tar.gz |
| StartedAt: 2023-03-25 04:40:23 -0000 (Sat, 25 Mar 2023) |
| EndedAt: 2023-03-25 04:58:17 -0000 (Sat, 25 Mar 2023) |
| EllapsedTime: 1073.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/site-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-03-12 r83975)
* 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.2 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 startup messages can be suppressed ... 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-devel_2023-03-12_r83975-bin/site-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-03-12 r83975) -- "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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:47:09.114458 INFO::preprocessReads.R/preprocessReads: starting...
2023-03-25 04:47:09.125571 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:47:09.131096 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-03-25 04:47:09.134372 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:47:12.388152 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:47:12.390578 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/chunks/chunk_000001/logs/progress.log
2023-03-25 04:47:15.24708 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2023-03-25 04:47:15.248976 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/chunks/chunk_000002/logs/progress.log
2023-03-25 04:47:18.084626 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-03-25 04:47:18.086411 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/chunks/chunk_000003/logs/progress.log
2023-03-25 04:47:20.947236 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2023-03-25 04:47:20.989453 DEBUG::tools.R/processChunks: done
2023-03-25 04:47:20.994466 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:47:20.997699 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/results/test_pe.adapter_contaminated_1.RData
2023-03-25 04:47:21.001743 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-03-25 04:47:21.004297 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/results/test_pe.adapter_contaminated_2.RData
2023-03-25 04:47:21.016803 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-03-25 04:47:21.019901 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/results/test_pe.summary_preprocess.tab
2023-03-25 04:47:21.024452 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/bams/processed.aligner_input_1.fastq ...
2023-03-25 04:47:21.030465 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/bams/processed.aligner_input_2.fastq ...
2023-03-25 04:47:21.035996 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/reports/shortReadReport_1 ...
2023-03-25 04:47:22.856287 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/reports/shortReadReport_2 ...
2023-03-25 04:47:24.398242 INFO::preprocessReads.R/preprocessReads: done
2023-03-25 04:47:24.45385 INFO::alignReads.R/alignReads: starting alignment...
2023-03-25 04:47:24.46118 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:47:27.789347 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:47:27.791456 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/chunks/chunk_000001/logs/progress.log
2023-03-25 04:47:30.902383 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2023-03-25 04:47:30.904542 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/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-03-25 04:47:33.664539 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-03-25 04:47:33.666586 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/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-03-25 04:47:36.396485 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2023-03-25 04:47:36.399602 DEBUG::tools.R/processChunks: done
2023-03-25 04:47:36.401415 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-03-25 04:47:36.706222 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-03-25 04:47:36.717346 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/results/test_pe.summary_alignment.tab
2023-03-25 04:47:36.727328 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/results/test_pe.summary_analyzed_bamstats.tab
2023-03-25 04:47:36.729616 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-03-25 04:47:37.027652 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.18057490c5efa/results/test_pe.summary_target_lengths.tab
2023-03-25 04:47:37.088035 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-03-25 04:47:37.089592 INFO::alignReads.R/alignReads: done
done successfully.
Executing test function test.alignReads.sparsechunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:47:37.394894 INFO::preprocessReads.R/preprocessReads: starting...
2023-03-25 04:47:37.398795 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:47:37.487732 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2023-03-25 04:47:37.494235 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:47:37.498379 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-03-25 04:47:37.501042 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:47:40.806117 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:47:40.808177 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/chunks/chunk_000001/logs/progress.log
2023-03-25 04:47:43.64791 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-03-25 04:47:43.650278 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/chunks/chunk_000002/logs/progress.log
2023-03-25 04:47:46.446367 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-03-25 04:47:46.448247 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/chunks/chunk_000003/logs/progress.log
2023-03-25 04:47:49.365094 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2023-03-25 04:47:49.366953 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/chunks/chunk_000004/logs/progress.log
2023-03-25 04:47:52.158098 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.046 minutes
2023-03-25 04:47:52.199276 DEBUG::tools.R/processChunks: done
2023-03-25 04:47:52.203902 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:47:52.207307 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/results/test_pe.adapter_contaminated_1.RData
2023-03-25 04:47:52.211706 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-03-25 04:47:52.214375 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/results/test_pe.adapter_contaminated_2.RData
2023-03-25 04:47:52.229 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-03-25 04:47:52.231949 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/results/test_pe.summary_preprocess.tab
2023-03-25 04:47:52.236808 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/bams/processed.aligner_input_1.fastq ...
2023-03-25 04:47:52.242839 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/bams/processed.aligner_input_2.fastq ...
2023-03-25 04:47:52.247516 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/reports/shortReadReport_1 ...
2023-03-25 04:47:54.071318 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.alignReads.sparsechunks.1805744152b118/reports/shortReadReport_2 ...
2023-03-25 04:47:55.570096 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.alignReadsOneSingleEnd ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:47:55.829347 INFO::alignReads.R/alignReadsChunk: running gsnap...
2023-03-25 04:47:55.835056 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/RtmpiYE9Dz/test.alignReadsOneSingleEnd.180574719007a5/bams/test.alignReads /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2023-03-25 04:47:56.052772 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2023-03-25 04:47:56.175045 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReadsOneSingleEnd.180574719007a5/results/test.alignReads.summary_alignment.tab
2023-03-25 04:47:56.225801 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.alignReadsOneSingleEnd.180574719007a5/results/test.alignReads.summary_analyzed_bamstats.tab
2023-03-25 04:47:56.227866 INFO::alignReads.R/alignReadsChunk: done
done successfully.
Executing test function test.annotateVariants ... Timing stopped at: 0.002 0 0.002
Error in DEACTIVATED("Skipped annotateVariants() test") :
Skipped annotateVariants() test
In addition: There were 11 warnings (use warnings() to see them)
done successfully.
Executing test function test.callVariantsVariantTools.genotype ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:47:56.686607 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.genotype.18057438f601ec/results/test_pe.coverage.RData
2023-03-25 04:47:56.689838 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpiYE9Dz/test.genotype.18057438f601ec/results/test_pe.coverage.bw
2023-03-25 04:47:56.892787 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.genotype.18057438f601ec/results/test_pe.summary_coverage.tab
2023-03-25 04:47:56.895677 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:48:09.021347 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:48:09.129132 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:48:09.150942 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:48:09.152877 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.genotype.18057438f601ec/results/test_pe.raw_variants.RData
2023-03-25 04:48:09.156145 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.genotype.18057438f601ec/results/test_pe.filtered_variants.RData
2023-03-25 04:48:09.157993 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-03-25 04:48:09.15962 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-03-25 04:48:09.692333 INFO::analyzeVariants.R/writeVCF: ...done
2023-03-25 04:48:09.69387 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2023-03-25 04:49:12.344836 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-03-25 04:49:12.902205 INFO::analyzeVariants.R/writeVCF: ...done
2023-03-25 04:49:12.903394 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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:49:13.45844 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:49:23.949658 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:49:24.038672 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:49:24.058438 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:49:24.060053 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.18057418398f91/results/test_pe.raw_variants.RData
2023-03-25 04:49:24.063188 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.18057418398f91/results/test_pe.filtered_variants.RData
2023-03-25 04:49:24.064832 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.filters ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:49:24.218721 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:49:34.510168 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:49:34.578337 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:49:34.598372 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:49:34.600063 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.filters.1805742423465/results/test_pe.raw_variants.RData
2023-03-25 04:49:34.603174 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.filters.1805742423465/results/test_pe.filtered_variants.RData
2023-03-25 04:49:34.604808 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-03-25 04:49:34.606332 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:49:45.590065 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:49:45.634577 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:49:45.654328 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:49:45.655961 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.filters.1805742423465/results/test_pe.raw_variants.RData
2023-03-25 04:49:45.65918 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.filters.1805742423465/results/test_pe.filtered_variants.RData
2023-03-25 04:49:45.661806 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.which ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:49:45.845587 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:49:45.847355 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2023-03-25 04:49:48.219429 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:49:48.30844 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:49:48.328489 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:49:48.33011 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.which.1805744b0d7187/results/test_pe.raw_variants.RData
2023-03-25 04:49:48.332215 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.wrap.callVariants.which.1805744b0d7187/results/test_pe.filtered_variants.RData
2023-03-25 04:49:48.333895 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.writeVCF.NULL ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:49:48.497584 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-03-25 04:49:48.499139 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.writeVCF.vcfStat ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:49:48.719564 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-03-25 04:49:49.004997 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-03-25 04:51:05.483717 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/ltwogysh/merged/results/bla.coverage.RData
2023-03-25 04:51:05.487093 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpiYE9Dz/ltwogysh/merged/results/bla.coverage.bw
2023-03-25 04:51:05.594174 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/ltwogysh/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.mergeCoverage.sparse ... 2023-03-25 04:51:06.788274 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/ikavezmo/merged/results/bla.coverage.RData
2023-03-25 04:51:06.790261 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpiYE9Dz/ikavezmo/merged/results/bla.coverage.bw
2023-03-25 04:51:06.804635 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/ikavezmo/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.checkConfig.analyzeVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.checkConfig.alignReads ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:08.571911 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-03-25 04:51:08.573406 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpiYE9Dz/test.detectRRNA.18057431d47807/bams/rRNA_contam/input1.fastq
2023-03-25 04:51:08.577777 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/RtmpiYE9Dz/test.detectRRNA.18057431d47807/bams/rRNA_contam/test_se /tmp/RtmpiYE9Dz/test.detectRRNA.18057431d47807/bams/rRNA_contam/input1.fastq 2>&1
2023-03-25 04:51:08.726773 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-03-25 04:51:08.728159 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.detectRRNA.paired_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:08.952106 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-03-25 04:51:08.953467 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpiYE9Dz/test.detectRRNA.paired_end.180574ab43690/bams/rRNA_contam/input1.fastq
2023-03-25 04:51:08.955618 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpiYE9Dz/test.detectRRNA.paired_end.180574ab43690/bams/rRNA_contam/input2.fastq
2023-03-25 04:51:08.958834 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/RtmpiYE9Dz/test.detectRRNA.paired_end.180574ab43690/bams/rRNA_contam/test_pe /tmp/RtmpiYE9Dz/test.detectRRNA.paired_end.180574ab43690/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpiYE9Dz/test.detectRRNA.paired_end.180574ab43690/bams/rRNA_contam/input2.fastq 2>&1
2023-03-25 04:51:09.243679 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-03-25 04:51:09.245073 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.getRRNAIds ... 2023-03-25 04:51:09.27151 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/RtmpiYE9Dz/test_get_rRNA_idshfengzyr/test_pe /tmp/RtmpiYE9Dz/test_get_rRNA_idshfengzyr/1.fastq -a paired /tmp/RtmpiYE9Dz/test_get_rRNA_idshfengzyr/2.fastq 2>&1
done successfully.
Executing test function test.getRRNAIds_random ... 2023-03-25 04:51:09.582167 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/RtmpiYE9Dz/test_get_rRNAIds_randomdbezxofr/test_pe /tmp/RtmpiYE9Dz/test_get_rRNAIds_randomdbezxofr/1.fastq 2>&1
done successfully.
Executing test function test.filterByLength ... 2023-03-25 04:51:09.829229 INFO::filterQuality.R/filterQuality: filterByLength...
2023-03-25 04:51:09.83102 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2023-03-25 04:51:09.832255 INFO::filterQuality.R/filterByLength: done
2023-03-25 04:51:09.894083 INFO::filterQuality.R/filterQuality: filterByLength...
2023-03-25 04:51:09.895318 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2023-03-25 04:51:09.896526 INFO::filterQuality.R/filterByLength: done
done successfully.
Executing test function test.isAboveQualityThresh ... done successfully.
Executing test function test.trimTailsByQuality ... 2023-03-25 04:51:09.964569 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-03-25 04:51:09.976717 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-03-25 04:51:09.978142 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-03-25 04:51:09.984216 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-03-25 04:51:09.985581 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-03-25 04:51:09.991628 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-03-25 04:51:09.992991 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-03-25 04:51:09.999017 INFO::preprocessReads.R/preprocessReadsChunk: done
done successfully.
Executing test function test.callVariantsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
In addition: There were 50 or more warnings (use warnings() to see the first 50)
done successfully.
Executing test function test.callVariantsGATK.withFiltering ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
done successfully.
Executing test function test.checkGATKJar ... Timing stopped at: 0 0 0
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") :
checkGATKJar() test needs gatk.path option set
done successfully.
Executing test function test.excludeVariantsByRegion ... done successfully.
Executing test function test.gatk ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") :
gatk() tests need gatk.path option set
done successfully.
Executing test function test.realignIndels ... Timing stopped at: 0 0 0
Error in DEACTIVATED("test.realignIndels() tests need gatk.path option set") :
test.realignIndels() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK.parallel ... Timing stopped at: 0.001 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test_zipUp ... done successfully.
Executing test function test.FastQStreamer.getReads.pefq ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:10.407352 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:10.410467 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:10.673907 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:10.833416 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-03-25 04:51:10.837077 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:10.840136 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:11.185437 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/reads.fastq.gz
done successfully.
Executing test function test.FastQStreamer.getReads.truncated ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:11.394614 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/truncated.fastq.gz
done successfully.
Executing test function test.FastQStreamer.subsampler.isdeterministic ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:11.658364 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:11.784317 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-03-25 04:51:11.7877 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:11.790781 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:12.113666 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:12.188464 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-03-25 04:51:12.191788 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:12.19479 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.mergeLanes ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:51:14.287081 INFO::preprocessReads.R/preprocessReads: starting...
2023-03-25 04:51:14.29411 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:51:14.298773 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-03-25 04:51:14.301739 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:51:17.901663 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:51:17.90373 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000001/logs/progress.log
2023-03-25 04:51:20.664167 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-03-25 04:51:20.666101 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000002/logs/progress.log
2023-03-25 04:51:23.421593 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-03-25 04:51:23.423553 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000003/logs/progress.log
2023-03-25 04:51:26.194867 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-03-25 04:51:26.270747 DEBUG::tools.R/processChunks: done
2023-03-25 04:51:26.274473 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:51:26.276819 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.adapter_contaminated_1.RData
2023-03-25 04:51:26.279753 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-03-25 04:51:26.281965 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.adapter_contaminated_2.RData
2023-03-25 04:51:26.294182 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-03-25 04:51:26.29701 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.summary_preprocess.tab
2023-03-25 04:51:26.30079 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/bams/processed.aligner_input_1.fastq ...
2023-03-25 04:51:26.306522 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/bams/processed.aligner_input_2.fastq ...
2023-03-25 04:51:26.311044 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/reports/shortReadReport_1 ...
2023-03-25 04:51:28.08031 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/reports/shortReadReport_2 ...
2023-03-25 04:51:29.478845 INFO::preprocessReads.R/preprocessReads: done
2023-03-25 04:51:29.540447 INFO::alignReads.R/alignReads: starting alignment...
2023-03-25 04:51:29.545578 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:51:33.259041 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:51:33.261334 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000001/logs/progress.log
2023-03-25 04:51:35.905318 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-03-25 04:51:35.9077 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/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-03-25 04:51:38.639781 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-03-25 04:51:38.642127 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/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-03-25 04:51:41.312229 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2023-03-25 04:51:41.315588 DEBUG::tools.R/processChunks: done
2023-03-25 04:51:41.317697 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-03-25 04:51:41.580842 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-03-25 04:51:41.590884 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.summary_alignment.tab
2023-03-25 04:51:41.600357 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.summary_analyzed_bamstats.tab
2023-03-25 04:51:41.602735 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-03-25 04:51:41.874079 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.summary_target_lengths.tab
2023-03-25 04:51:41.932747 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-03-25 04:51:41.934046 INFO::alignReads.R/alignReads: done
2023-03-25 04:51:41.999839 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-03-25 04:51:42.025936 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:51:45.940926 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:51:45.943194 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000001/logs/progress.log
2023-03-25 04:51:48.481897 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2023-03-25 04:51:48.484053 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000002/logs/progress.log
2023-03-25 04:51:51.048846 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2023-03-25 04:51:51.051529 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000003/logs/progress.log
2023-03-25 04:51:53.592705 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2023-03-25 04:51:53.595937 DEBUG::tools.R/processChunks: done
2023-03-25 04:51:53.598168 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-03-25 04:51:53.615663 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.counts_exon.tab
2023-03-25 04:51:53.629538 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.counts_exon_disjoint.tab
2023-03-25 04:51:53.638882 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.counts_gene.tab
2023-03-25 04:51:53.646912 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.counts_gene_coding.tab
2023-03-25 04:51:53.654407 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.counts_gene_exonic.tab
2023-03-25 04:51:53.662027 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.counts_intergenic.tab
2023-03-25 04:51:53.673716 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.counts_intron.tab
2023-03-25 04:51:53.67738 INFO::countGenomicFeatures.R/mergeCounts: done
2023-03-25 04:51:53.685239 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.summary_counts.tab
2023-03-25 04:51:53.687535 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-03-25 04:51:54.04425 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-03-25 04:51:54.045513 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-03-25 04:51:54.110826 INFO::coverage.R/calculateCoverage: starting...
2023-03-25 04:51:54.115743 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:51:57.662531 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:51:57.665003 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000001/logs/progress.log
2023-03-25 04:51:59.860131 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2023-03-25 04:51:59.862848 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000002/logs/progress.log
2023-03-25 04:52:02.060672 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2023-03-25 04:52:02.062954 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/chunks/chunk_000003/logs/progress.log
2023-03-25 04:52:04.254055 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2023-03-25 04:52:04.257413 DEBUG::tools.R/processChunks: done
2023-03-25 04:52:05.912773 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.coverage.RData
2023-03-25 04:52:05.914784 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.coverage.bw
2023-03-25 04:52:05.929938 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.summary_coverage.tab
2023-03-25 04:52:05.931774 INFO::coverage.R/calculateCoverage: done
2023-03-25 04:52:05.934217 INFO::analyzeVariants/analyzeVariants: starting ...
2023-03-25 04:52:06.006543 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:52:09.493904 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:52:09.589278 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:52:09.610616 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:52:09.61241 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.raw_variants.RData
2023-03-25 04:52:09.614521 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.filtered_variants.RData
2023-03-25 04:52:09.616191 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-03-25 04:52:09.617537 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-03-25 04:52:09.912612 INFO::analyzeVariants.R/writeVCF: ...done
2023-03-25 04:52:10.044175 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/results/test_pe.summary_variants.tab
2023-03-25 04:52:10.046706 INFO::analyzeVariants/analyzeVariants: done
2023-03-25 04:52:10.050715 INFO::Pipeline run successful.
2023-03-25 04:52:10.218163 INFO::mergeLanes.R/doMergeLanes: starting...
2023-03-25 04:52:10.224214 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:52:10.227332 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.adapter_contaminated_1.RData
2023-03-25 04:52:10.231268 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-03-25 04:52:10.234162 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.adapter_contaminated_2.RData
2023-03-25 04:52:10.249464 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-03-25 04:52:10.252735 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.summary_preprocess.tab
2023-03-25 04:52:10.255567 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-03-25 04:52:10.594456 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-03-25 04:52:10.604469 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.summary_alignment.tab
2023-03-25 04:52:10.615754 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.summary_analyzed_bamstats.tab
2023-03-25 04:52:10.618577 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-03-25 04:52:10.910007 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.summary_target_lengths.tab
2023-03-25 04:52:10.97293 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-03-25 04:52:11.012583 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-03-25 04:52:11.038578 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.counts_exon.tab
2023-03-25 04:52:11.054439 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.counts_exon_disjoint.tab
2023-03-25 04:52:11.064248 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.counts_gene.tab
2023-03-25 04:52:11.072512 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.counts_gene_coding.tab
2023-03-25 04:52:11.080718 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.counts_gene_exonic.tab
2023-03-25 04:52:11.089279 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.counts_intergenic.tab
2023-03-25 04:52:11.104783 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.counts_intron.tab
2023-03-25 04:52:11.108746 INFO::countGenomicFeatures.R/mergeCounts: done
2023-03-25 04:52:11.117841 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.summary_counts.tab
2023-03-25 04:52:11.120453 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-03-25 04:52:11.393429 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-03-25 04:52:13.670641 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.coverage.RData
2023-03-25 04:52:13.674027 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.coverage.bw
2023-03-25 04:52:13.689082 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.summary_coverage.tab
2023-03-25 04:52:13.724018 INFO::analyzeVariants/analyzeVariants: starting ...
2023-03-25 04:52:13.789756 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:52:17.18626 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:52:17.27784 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:52:17.298494 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:52:17.300309 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.raw_variants.RData
2023-03-25 04:52:17.302374 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.filtered_variants.RData
2023-03-25 04:52:17.304064 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-03-25 04:52:17.305409 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-03-25 04:52:17.589085 INFO::analyzeVariants.R/writeVCF: ...done
2023-03-25 04:52:17.715238 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.mergeLanes.1805747e1acbed/merged/results/merged.summary_variants.tab
2023-03-25 04:52:17.717714 INFO::analyzeVariants/analyzeVariants: done
2023-03-25 04:52:17.721127 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
done successfully.
Executing test function test.markDuplicates ... Timing stopped at: 0 0.001 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/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:52:18.057478 INFO::preprocessReads.R/preprocessReads: starting...
2023-03-25 04:52:18.065236 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:52:18.07004 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-03-25 04:52:18.073218 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:52:21.954664 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:52:21.956826 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/chunks/chunk_000001/logs/progress.log
2023-03-25 04:52:24.740355 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-03-25 04:52:24.81216 DEBUG::tools.R/processChunks: done
2023-03-25 04:52:24.815252 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:52:24.817362 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/results/test_pe.adapter_contaminated_1.RData
2023-03-25 04:52:24.819715 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-03-25 04:52:24.821662 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/results/test_pe.adapter_contaminated_2.RData
2023-03-25 04:52:24.832747 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-03-25 04:52:24.835354 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/results/test_pe.summary_preprocess.tab
2023-03-25 04:52:24.838321 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/bams/processed.aligner_input_1.fastq ...
2023-03-25 04:52:24.843303 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/bams/processed.aligner_input_2.fastq ...
2023-03-25 04:52:24.848542 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/reports/shortReadReport_1 ...
2023-03-25 04:52:26.683499 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.preprocessReads.1805741f80bcf7/reports/shortReadReport_2 ...
2023-03-25 04:52:28.448276 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads.minichunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:52:28.714379 INFO::preprocessReads.R/preprocessReads: starting...
2023-03-25 04:52:28.722826 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:52:28.728561 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-03-25 04:52:28.731816 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:52:32.204852 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:52:32.206866 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/chunks/chunk_000001/logs/progress.log
2023-03-25 04:52:34.964214 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-03-25 04:52:34.966152 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/chunks/chunk_000002/logs/progress.log
2023-03-25 04:52:37.711793 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-03-25 04:52:37.713628 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/chunks/chunk_000003/logs/progress.log
2023-03-25 04:52:40.575826 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2023-03-25 04:52:40.646007 DEBUG::tools.R/processChunks: done
2023-03-25 04:52:40.649972 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:52:40.65245 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/results/test_pe.adapter_contaminated_1.RData
2023-03-25 04:52:40.655602 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-03-25 04:52:40.657971 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/results/test_pe.adapter_contaminated_2.RData
2023-03-25 04:52:40.669628 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-03-25 04:52:40.67247 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/results/test_pe.summary_preprocess.tab
2023-03-25 04:52:40.676341 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/bams/processed.aligner_input_1.fastq ...
2023-03-25 04:52:40.682178 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/bams/processed.aligner_input_2.fastq ...
2023-03-25 04:52:40.68706 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/reports/shortReadReport_1 ...
2023-03-25 04:52:42.499958 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.preprocessReads.minichunks.1805747f6fcf7f/reports/shortReadReport_2 ...
2023-03-25 04:52:44.046432 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads_single_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:52:44.376079 INFO::preprocessReads.R/preprocessReads: starting...
2023-03-25 04:52:44.384016 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-03-25 04:52:44.387295 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:52:47.707483 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:52:47.709521 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpiYE9Dz/test.preprocessReads_single_end.18057419570824/chunks/chunk_000001/logs/progress.log
2023-03-25 04:52:50.168049 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2023-03-25 04:52:50.228875 DEBUG::tools.R/processChunks: done
2023-03-25 04:52:50.232042 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:52:50.234256 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads_single_end.18057419570824/results/test_se.adapter_contaminated_1.RData
2023-03-25 04:52:50.242595 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-03-25 04:52:50.245003 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.preprocessReads_single_end.18057419570824/results/test_se.summary_preprocess.tab
2023-03-25 04:52:50.247474 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpiYE9Dz/test.preprocessReads_single_end.18057419570824/bams/processed.aligner_input_1.fastq ...
2023-03-25 04:52:50.252293 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpiYE9Dz/test.preprocessReads_single_end.18057419570824/reports/shortReadReport_1 ...
2023-03-25 04:52:51.993175 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-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:52:52.77424 INFO::preprocessReads.R/preprocessReads: starting...
2023-03-25 04:52:52.78202 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2023-03-25 04:52:52.788642 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2023-03-25 04:52:52.791789 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:52:56.385822 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:52:56.388052 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-03-25 04:52:59.392398 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2023-03-25 04:52:59.459702 DEBUG::tools.R/processChunks: done
2023-03-25 04:52:59.462653 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-03-25 04:52:59.464734 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2023-03-25 04:52:59.466954 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-03-25 04:52:59.468954 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2023-03-25 04:52:59.476882 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-03-25 04:52:59.479252 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2023-03-25 04:52:59.482051 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2023-03-25 04:52:59.488259 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2023-03-25 04:52:59.494074 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2023-03-25 04:53:01.545943 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2023-03-25 04:53:03.550902 INFO::preprocessReads.R/preprocessReads: done
2023-03-25 04:53:03.614211 INFO::alignReads.R/alignReads: starting alignment...
2023-03-25 04:53:03.619373 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:53:07.118473 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:53:07.120664 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-03-25 04:53:12.930692 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.097 minutes
2023-03-25 04:53:12.93385 DEBUG::tools.R/processChunks: done
2023-03-25 04:53:12.935689 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2023-03-25 04:53:12.975068 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-03-25 04:53:12.983263 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2023-03-25 04:53:12.990651 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2023-03-25 04:53:12.993357 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-03-25 04:53:13.182638 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2023-03-25 04:53:13.239933 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-03-25 04:53:13.241182 INFO::alignReads.R/alignReads: done
2023-03-25 04:53:13.306051 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-03-25 04:53:13.327477 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:53:16.88992 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:53:16.892406 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-03-25 04:53:19.526992 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-03-25 04:53:19.53018 DEBUG::tools.R/processChunks: done
2023-03-25 04:53:19.532239 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-03-25 04:53:19.544313 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2023-03-25 04:53:19.554149 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2023-03-25 04:53:19.561378 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2023-03-25 04:53:19.566385 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2023-03-25 04:53:19.571542 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2023-03-25 04:53:19.576654 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2023-03-25 04:53:19.584494 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2023-03-25 04:53:19.58868 INFO::countGenomicFeatures.R/mergeCounts: done
2023-03-25 04:53:19.593416 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2023-03-25 04:53:19.595685 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-03-25 04:53:19.862402 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-03-25 04:53:19.863663 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-03-25 04:53:19.935524 INFO::coverage.R/calculateCoverage: starting...
2023-03-25 04:53:19.940905 DEBUG::tools.R/processChunks: starting...
2023-03-25 04:53:23.386173 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-03-25 04:53:23.388471 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-03-25 04:53:25.756082 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2023-03-25 04:53:25.759665 DEBUG::tools.R/processChunks: done
2023-03-25 04:53:27.760114 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2023-03-25 04:53:27.762255 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2023-03-25 04:53:27.881362 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2023-03-25 04:53:27.883402 INFO::coverage.R/calculateCoverage: done
2023-03-25 04:53:27.885308 INFO::analyzeVariants/analyzeVariants: starting ...
2023-03-25 04:53:27.951472 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-03-25 04:53:40.499727 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-03-25 04:53:40.596621 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-03-25 04:53:40.618489 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-03-25 04:53:40.620272 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2023-03-25 04:53:40.623639 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2023-03-25 04:53:40.625452 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-03-25 04:53:40.626779 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-03-25 04:53:40.923748 INFO::analyzeVariants.R/writeVCF: ...done
2023-03-25 04:53:41.056605 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2023-03-25 04:53:41.059342 INFO::analyzeVariants/analyzeVariants: done
2023-03-25 04:53:41.065625 INFO::Pipeline run successful.
done successfully.
Executing test function test.calculateTargetLength ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpiYE9Dz/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt
2023-03-25 04:53:41.367051 INFO::io.R/saveWithID: saving file= /tmp/RtmpiYE9Dz/test.calcTargetLengths.18057426aef040/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 -- Sat Mar 25 04:53:54 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-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.alignReads.R
test.alignReads: (2 checks) ... OK (29.5 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (18.47 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.65 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (77.05 seconds)
test.wrap.callVariants: (4 checks) ... OK (10.78 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (21.6 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.67 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.16 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.63 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.bamUtils.R
test.isFirstFragment: (5 checks) ... OK (0 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R
test.buildCountsGRangesList: (3 checks) ... OK (38.36 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (35.66 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R
test.computeCoverage: (9 checks) ... OK (0.86 seconds)
test.isSparse: (5 checks) ... OK (0.11 seconds)
test.mergeCoverage: (1 checks) ... OK (1.46 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.24 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.checkConfig.R
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.2 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.config.R
test.checkConfig: (5 checks) ... OK (0.47 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.54 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-devel_2023-03-12_r83975-bin/site-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.1 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R
test.detectRRNA: (1 checks) ... OK (0.37 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.52 seconds)
test.getRRNAIds: (1 checks) ... OK (0.31 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.27 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.filterQuality.R
test.filterByLength: (2 checks) ... OK (0.07 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-devel_2023-03-12_r83975-bin/site-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.2 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-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.io.R
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.27 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.5 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.22 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.25 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.88 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (1.32 seconds)
test.getObjectFilename: (4 checks) ... OK (0.01 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.19 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R
test.mergeLanes: (6 checks) ... OK (63.89 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-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-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R
test.preprocessReads: (5 checks) ... OK (10.7 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.6 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (7.95 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-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-devel_2023-03-12_r83975-bin/site-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.07 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.runPipeline.R
test.runPipeline: (1 checks) ... OK (48.6 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.targetLengths.R
test.calculateTargetLength: (4 checks) ... OK (0.3 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.tools.R
test.sclapply: (10 checks) ... OK (12.48 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.trimReads.R
test.truncateReads: (7 checks) ... OK (0.07 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.24 seconds)
runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
>
> proc.time()
user system elapsed
310.323 67.944 426.501
HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings
| name | user | system | elapsed | |
| HTSeqGenie | 0.001 | 0.000 | 0.000 | |
| buildGenomicFeaturesFromTxDb | 0 | 0 | 0 | |
| runPipeline | 0 | 0 | 0 | |