| Back to Build/check report for BioC 3.18: simplified long |
|
This page was generated on 2023-06-06 11:00:33 -0000 (Tue, 06 Jun 2023).
| Hostname | OS | Arch (*) | R version | Installed pkgs |
|---|---|---|---|---|
| kunpeng2 | Linux (openEuler 22.03 LTS-SP1) | aarch64 | 4.3.0 (2023-04-21) -- "Already Tomorrow" | 4366 |
| 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: - 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 Troubleshooting Build Report for more information. - Use the following Renviron settings to reproduce errors and warnings. Note: If "R CMD check" recently failed on the Linux builder over a missing dependency, add the missing dependency to "Suggests" in your DESCRIPTION file. See the Renviron.bioc for details. |
| Package 939/2199 | Hostname | OS / Arch | INSTALL | BUILD | CHECK | BUILD BIN | ||||||||
| HTSeqGenie 4.31.0 (landing page) Jens Reeder
| kunpeng2 | Linux (openEuler 22.03 LTS-SP1) / aarch64 | OK | OK | OK | |||||||||
| Package: HTSeqGenie |
| Version: 4.31.0 |
| Command: /home/biocbuild/R/R-4.3.0/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/R/R-4.3.0/site-library --timings HTSeqGenie_4.31.0.tar.gz |
| StartedAt: 2023-06-06 00:11:02 -0000 (Tue, 06 Jun 2023) |
| EndedAt: 2023-06-06 00:30:05 -0000 (Tue, 06 Jun 2023) |
| EllapsedTime: 1142.7 seconds |
| RetCode: 0 |
| Status: OK |
| CheckDir: HTSeqGenie.Rcheck |
| Warnings: 0 |
##############################################################################
##############################################################################
###
### Running command:
###
### /home/biocbuild/R/R-4.3.0/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/R/R-4.3.0/site-library --timings HTSeqGenie_4.31.0.tar.gz
###
##############################################################################
##############################################################################
* using log directory ‘/home/biocbuild/bbs-3.18-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.3.0 (2023-04-21)
* using platform: aarch64-unknown-linux-gnu (64-bit)
* R was compiled by
gcc (GCC) 10.3.1
GNU Fortran (GCC) 10.3.1
* running under: openEuler 22.03 (LTS-SP1)
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.31.0’
* checking package namespace information ... OK
* checking package dependencies ... OK
* checking if this is a source package ... OK
* checking if there is a namespace ... OK
* checking for hidden files and directories ... NOTE
Found the following hidden files and directories:
.BBSoptions
These were most likely included in error. See section ‘Package
structure’ in the ‘Writing R Extensions’ manual.
* checking for portable file names ... OK
* checking for sufficient/correct file permissions ... OK
* checking whether package ‘HTSeqGenie’ can be installed ... OK
* checking installed package size ... 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 loading without being on the library search path ... 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.18-bioc/meat/HTSeqGenie.Rcheck/00check.log’
for details.
HTSeqGenie.Rcheck/00install.out
############################################################################## ############################################################################## ### ### Running command: ### ### /home/biocbuild/R/R-4.3.0/bin/R CMD INSTALL HTSeqGenie ### ############################################################################## ############################################################################## * installing to library ‘/home/biocbuild/R/R-4.3.0/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 version 4.3.0 (2023-04-21) -- "Already Tomorrow"
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 object is masked from 'package:utils':
findMatches
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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:18:41.623361 INFO::preprocessReads.R/preprocessReads: starting...
2023-06-06 00:18:41.632392 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:18:41.637574 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-06-06 00:18:41.640321 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:18:44.729155 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:18:44.731155 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/chunks/chunk_000001/logs/progress.log
2023-06-06 00:18:47.589384 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2023-06-06 00:18:47.591216 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/chunks/chunk_000002/logs/progress.log
2023-06-06 00:18:50.453848 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.048 minutes
2023-06-06 00:18:50.455688 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/chunks/chunk_000003/logs/progress.log
2023-06-06 00:18:53.300087 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2023-06-06 00:18:53.340691 DEBUG::tools.R/processChunks: done
2023-06-06 00:18:53.345339 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:18:53.348274 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/results/test_pe.adapter_contaminated_1.RData
2023-06-06 00:18:53.351888 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-06-06 00:18:53.354244 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/results/test_pe.adapter_contaminated_2.RData
2023-06-06 00:18:53.366708 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-06-06 00:18:53.3697 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/results/test_pe.summary_preprocess.tab
2023-06-06 00:18:53.373984 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/bams/processed.aligner_input_1.fastq ...
2023-06-06 00:18:53.380226 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/bams/processed.aligner_input_2.fastq ...
2023-06-06 00:18:53.38508 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/reports/shortReadReport_1 ...
2023-06-06 00:18:55.270018 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/reports/shortReadReport_2 ...
2023-06-06 00:18:58.328095 INFO::preprocessReads.R/preprocessReads: done
2023-06-06 00:18:58.377721 INFO::alignReads.R/alignReads: starting alignment...
2023-06-06 00:18:58.383777 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:19:01.579176 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:19:01.581351 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/chunks/chunk_000001/logs/progress.log
2023-06-06 00:19:04.562792 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2023-06-06 00:19:04.565065 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/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-06-06 00:19:07.278579 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2023-06-06 00:19:07.280797 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/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-06-06 00:19:09.978514 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2023-06-06 00:19:09.981896 DEBUG::tools.R/processChunks: done
2023-06-06 00:19:09.98373 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-06-06 00:19:10.306402 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-06-06 00:19:10.318389 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/results/test_pe.summary_alignment.tab
2023-06-06 00:19:10.329463 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/results/test_pe.summary_analyzed_bamstats.tab
2023-06-06 00:19:10.332048 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-06-06 00:19:10.608618 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.3983df407c04f9/results/test_pe.summary_target_lengths.tab
2023-06-06 00:19:10.670287 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-06-06 00:19:10.671817 INFO::alignReads.R/alignReads: done
done successfully.
Executing test function test.alignReads.sparsechunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:19:10.975214 INFO::preprocessReads.R/preprocessReads: starting...
2023-06-06 00:19:10.978801 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:19:11.066453 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2023-06-06 00:19:11.073153 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:19:11.077589 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-06-06 00:19:11.080306 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:19:14.31729 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:19:14.319383 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/chunks/chunk_000001/logs/progress.log
2023-06-06 00:19:17.146978 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-06-06 00:19:17.149163 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/chunks/chunk_000002/logs/progress.log
2023-06-06 00:19:19.934906 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-06-06 00:19:19.93682 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/chunks/chunk_000003/logs/progress.log
2023-06-06 00:19:22.833637 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2023-06-06 00:19:22.835508 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/chunks/chunk_000004/logs/progress.log
2023-06-06 00:19:25.613976 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.046 minutes
2023-06-06 00:19:25.656638 DEBUG::tools.R/processChunks: done
2023-06-06 00:19:25.661051 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:19:25.664235 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/results/test_pe.adapter_contaminated_1.RData
2023-06-06 00:19:25.668351 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-06-06 00:19:25.670921 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/results/test_pe.adapter_contaminated_2.RData
2023-06-06 00:19:25.685007 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-06-06 00:19:25.688093 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/results/test_pe.summary_preprocess.tab
2023-06-06 00:19:25.692897 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/bams/processed.aligner_input_1.fastq ...
2023-06-06 00:19:25.699784 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/bams/processed.aligner_input_2.fastq ...
2023-06-06 00:19:25.705463 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/reports/shortReadReport_1 ...
2023-06-06 00:19:27.485494 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.alignReads.sparsechunks.3983df1a26ce8a/reports/shortReadReport_2 ...
2023-06-06 00:19:30.45536 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.alignReadsOneSingleEnd ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:19:30.672855 INFO::alignReads.R/alignReadsChunk: running gsnap...
2023-06-06 00:19:30.679531 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/Rtmpm9hAgx/test.alignReadsOneSingleEnd.3983dfc41ab12/bams/test.alignReads /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2023-06-06 00:19:30.825204 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2023-06-06 00:19:30.958677 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReadsOneSingleEnd.3983dfc41ab12/results/test.alignReads.summary_alignment.tab
2023-06-06 00:19:31.008066 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.alignReadsOneSingleEnd.3983dfc41ab12/results/test.alignReads.summary_analyzed_bamstats.tab
2023-06-06 00:19:31.01016 INFO::alignReads.R/alignReadsChunk: done
done successfully.
Executing test function test.annotateVariants ... Timing stopped at: 0.004 0 0.004
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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:19:31.455939 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.genotype.3983df795a5ea6/results/test_pe.coverage.RData
2023-06-06 00:19:31.458368 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpm9hAgx/test.genotype.3983df795a5ea6/results/test_pe.coverage.bw
2023-06-06 00:19:31.639758 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.genotype.3983df795a5ea6/results/test_pe.summary_coverage.tab
2023-06-06 00:19:31.64202 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:19:44.019952 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:19:44.139322 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:19:44.162841 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:19:44.164793 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.genotype.3983df795a5ea6/results/test_pe.raw_variants.RData
2023-06-06 00:19:44.167661 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.genotype.3983df795a5ea6/results/test_pe.filtered_variants.RData
2023-06-06 00:19:44.169378 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-06-06 00:19:44.170961 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-06-06 00:19:44.701036 INFO::analyzeVariants.R/writeVCF: ...done
2023-06-06 00:19:44.702451 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2023-06-06 00:20:52.612933 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-06-06 00:20:53.246427 INFO::analyzeVariants.R/writeVCF: ...done
2023-06-06 00:20:53.247789 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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:20:53.854811 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:21:05.858894 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:21:05.963286 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:21:05.986259 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:21:05.988122 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.3983df58ad52cb/results/test_pe.raw_variants.RData
2023-06-06 00:21:05.990986 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.3983df58ad52cb/results/test_pe.filtered_variants.RData
2023-06-06 00:21:05.992754 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.filters ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:21:06.178432 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:21:18.119687 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:21:18.200325 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:21:18.223671 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:21:18.225484 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.filters.3983df5e921ca1/results/test_pe.raw_variants.RData
2023-06-06 00:21:18.228371 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.filters.3983df5e921ca1/results/test_pe.filtered_variants.RData
2023-06-06 00:21:18.229943 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-06-06 00:21:18.231689 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:21:30.113608 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:21:30.167971 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:21:30.191592 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:21:30.193416 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.filters.3983df5e921ca1/results/test_pe.raw_variants.RData
2023-06-06 00:21:30.196339 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.filters.3983df5e921ca1/results/test_pe.filtered_variants.RData
2023-06-06 00:21:30.198636 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.wrap.callVariants.which ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:21:30.405643 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:21:30.407592 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2023-06-06 00:21:33.114073 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:21:33.212266 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:21:33.234567 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:21:33.236321 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.which.3983df4d80ec27/results/test_pe.raw_variants.RData
2023-06-06 00:21:33.238341 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.wrap.callVariants.which.3983df4d80ec27/results/test_pe.filtered_variants.RData
2023-06-06 00:21:33.239984 INFO::analyzeVariants.R/wrap.callVariants: ...done
done successfully.
Executing test function test.writeVCF.NULL ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:21:33.408782 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-06-06 00:21:33.41038 INFO::analyzeVariants.R/writeVCF: ...done
done successfully.
Executing test function test.writeVCF.vcfStat ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:21:33.644028 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-06-06 00:21:33.946221 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-06-06 00:22:45.482794 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/cyvkuztx/merged/results/bla.coverage.RData
2023-06-06 00:22:45.486083 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpm9hAgx/cyvkuztx/merged/results/bla.coverage.bw
2023-06-06 00:22:45.597875 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/cyvkuztx/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.mergeCoverage.sparse ... 2023-06-06 00:22:46.949008 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/sxtagbkh/merged/results/bla.coverage.RData
2023-06-06 00:22:46.950986 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpm9hAgx/sxtagbkh/merged/results/bla.coverage.bw
2023-06-06 00:22:46.966533 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/sxtagbkh/merged/results/bla.summary_coverage.tab
done successfully.
Executing test function test.checkConfig.analyzeVariants ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.checkConfig.alignReads ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:48.712435 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-06-06 00:22:48.713913 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpm9hAgx/test.detectRRNA.3983df45418297/bams/rRNA_contam/input1.fastq
2023-06-06 00:22:48.71883 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/Rtmpm9hAgx/test.detectRRNA.3983df45418297/bams/rRNA_contam/test_se /tmp/Rtmpm9hAgx/test.detectRRNA.3983df45418297/bams/rRNA_contam/input1.fastq 2>&1
2023-06-06 00:22:48.826527 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-06-06 00:22:48.827986 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.detectRRNA.paired_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:48.995455 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-06-06 00:22:48.996771 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpm9hAgx/test.detectRRNA.paired_end.3983df1275444e/bams/rRNA_contam/input1.fastq
2023-06-06 00:22:48.998936 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpm9hAgx/test.detectRRNA.paired_end.3983df1275444e/bams/rRNA_contam/input2.fastq
2023-06-06 00:22:49.00222 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/Rtmpm9hAgx/test.detectRRNA.paired_end.3983df1275444e/bams/rRNA_contam/test_pe /tmp/Rtmpm9hAgx/test.detectRRNA.paired_end.3983df1275444e/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmpm9hAgx/test.detectRRNA.paired_end.3983df1275444e/bams/rRNA_contam/input2.fastq 2>&1
2023-06-06 00:22:49.299054 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-06-06 00:22:49.300514 INFO::detectRRNA.R/detectRRNA: done
done successfully.
Executing test function test.getRRNAIds ... 2023-06-06 00:22:49.329856 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/Rtmpm9hAgx/test_get_rRNA_idsueyqjnza/test_pe /tmp/Rtmpm9hAgx/test_get_rRNA_idsueyqjnza/1.fastq -a paired /tmp/Rtmpm9hAgx/test_get_rRNA_idsueyqjnza/2.fastq 2>&1
done successfully.
Executing test function test.getRRNAIds_random ... 2023-06-06 00:22:49.613961 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/Rtmpm9hAgx/test_get_rRNAIds_randomcatqsujx/test_pe /tmp/Rtmpm9hAgx/test_get_rRNAIds_randomcatqsujx/1.fastq 2>&1
done successfully.
Executing test function test.filterByLength ... 2023-06-06 00:22:49.785088 INFO::filterQuality.R/filterQuality: filterByLength...
2023-06-06 00:22:49.787205 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2023-06-06 00:22:49.78861 INFO::filterQuality.R/filterByLength: done
2023-06-06 00:22:49.860567 INFO::filterQuality.R/filterQuality: filterByLength...
2023-06-06 00:22:49.861935 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2023-06-06 00:22:49.863328 INFO::filterQuality.R/filterByLength: done
done successfully.
Executing test function test.isAboveQualityThresh ... done successfully.
Executing test function test.trimTailsByQuality ... 2023-06-06 00:22:49.943994 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-06-06 00:22:49.958657 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-06-06 00:22:49.960366 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-06-06 00:22:49.967945 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-06-06 00:22:49.969646 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-06-06 00:22:49.97713 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-06-06 00:22:49.978704 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-06-06 00:22:49.98551 INFO::preprocessReads.R/preprocessReadsChunk: done
done successfully.
Executing test function test.callVariantsGATK ... Timing stopped at: 0.001 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
In addition: There were 50 or more warnings (use warnings() to see the first 50)
done successfully.
Executing test function test.callVariantsGATK.withFiltering ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") :
callVariantsGATK() tests need gatk.path option set
done successfully.
Executing test function test.checkGATKJar ... Timing stopped at: 0 0 0
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") :
checkGATKJar() test needs gatk.path option set
done successfully.
Executing test function test.excludeVariantsByRegion ... done successfully.
Executing test function test.gatk ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") :
gatk() tests need gatk.path option set
done successfully.
Executing test function test.realignIndels ... Timing stopped at: 0 0 0
Error in DEACTIVATED("test.realignIndels() tests need gatk.path option set") :
test.realignIndels() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test.realignIndelsGATK.parallel ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") :
realignIndelsGATK() tests need gatk.path option set
done successfully.
Executing test function test_zipUp ... done successfully.
Executing test function test.FastQStreamer.getReads.pefq ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:50.368868 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:50.372263 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:50.633784 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:50.743247 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-06-06 00:22:50.747214 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:50.750651 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:52.2948 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:52.501499 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:52.695641 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:52.768877 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-06-06 00:22:52.772593 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:52.776194 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:53.05382 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:53.127586 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-06-06 00:22:53.13126 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:53.134699 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
done successfully.
Executing test function test.mergeLanes ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:22:54.020253 INFO::preprocessReads.R/preprocessReads: starting...
2023-06-06 00:22:54.026591 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:22:54.030987 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-06-06 00:22:54.033674 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:22:57.429827 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:22:57.431903 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000001/logs/progress.log
2023-06-06 00:23:00.16572 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-06-06 00:23:00.167716 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000002/logs/progress.log
2023-06-06 00:23:02.891492 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2023-06-06 00:23:02.893335 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000003/logs/progress.log
2023-06-06 00:23:05.671575 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-06-06 00:23:05.746629 DEBUG::tools.R/processChunks: done
2023-06-06 00:23:05.750906 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:23:05.753259 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.adapter_contaminated_1.RData
2023-06-06 00:23:05.756357 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-06-06 00:23:05.758609 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.adapter_contaminated_2.RData
2023-06-06 00:23:05.769872 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-06-06 00:23:05.772683 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.summary_preprocess.tab
2023-06-06 00:23:05.776267 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/bams/processed.aligner_input_1.fastq ...
2023-06-06 00:23:05.783008 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/bams/processed.aligner_input_2.fastq ...
2023-06-06 00:23:05.788596 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/reports/shortReadReport_1 ...
2023-06-06 00:23:07.721973 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/reports/shortReadReport_2 ...
2023-06-06 00:23:09.278665 INFO::preprocessReads.R/preprocessReads: done
2023-06-06 00:23:09.351991 INFO::alignReads.R/alignReads: starting alignment...
2023-06-06 00:23:09.356628 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:23:14.106831 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:23:14.109308 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000001/logs/progress.log
2023-06-06 00:23:16.776647 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-06-06 00:23:16.778872 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/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-06-06 00:23:19.452752 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2023-06-06 00:23:19.45496 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/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-06-06 00:23:22.121132 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2023-06-06 00:23:22.12475 DEBUG::tools.R/processChunks: done
2023-06-06 00:23:22.12688 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-06-06 00:23:22.411308 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-06-06 00:23:22.421473 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.summary_alignment.tab
2023-06-06 00:23:22.43142 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.summary_analyzed_bamstats.tab
2023-06-06 00:23:22.433923 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-06-06 00:23:22.681497 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.summary_target_lengths.tab
2023-06-06 00:23:22.7405 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-06-06 00:23:22.741875 INFO::alignReads.R/alignReads: done
2023-06-06 00:23:22.817065 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-06-06 00:23:22.837864 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:23:26.330787 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:23:26.33317 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000001/logs/progress.log
2023-06-06 00:23:28.895988 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2023-06-06 00:23:28.898256 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000002/logs/progress.log
2023-06-06 00:23:31.47264 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2023-06-06 00:23:31.474916 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000003/logs/progress.log
2023-06-06 00:23:34.047403 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2023-06-06 00:23:34.05113 DEBUG::tools.R/processChunks: done
2023-06-06 00:23:34.053329 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-06-06 00:23:34.071101 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.counts_exon.tab
2023-06-06 00:23:34.084982 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.counts_exon_disjoint.tab
2023-06-06 00:23:34.094441 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.counts_gene.tab
2023-06-06 00:23:34.101907 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.counts_gene_coding.tab
2023-06-06 00:23:34.109341 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.counts_gene_exonic.tab
2023-06-06 00:23:34.116938 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.counts_intergenic.tab
2023-06-06 00:23:34.128723 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.counts_intron.tab
2023-06-06 00:23:34.132492 INFO::countGenomicFeatures.R/mergeCounts: done
2023-06-06 00:23:34.140553 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.summary_counts.tab
2023-06-06 00:23:34.142846 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-06-06 00:23:34.483272 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-06-06 00:23:34.484577 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-06-06 00:23:34.557977 INFO::coverage.R/calculateCoverage: starting...
2023-06-06 00:23:34.562658 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:23:38.105297 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:23:38.107758 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000001/logs/progress.log
2023-06-06 00:23:40.2997 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2023-06-06 00:23:40.301883 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000002/logs/progress.log
2023-06-06 00:23:42.507371 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2023-06-06 00:23:42.509684 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/chunks/chunk_000003/logs/progress.log
2023-06-06 00:23:44.714209 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2023-06-06 00:23:44.717681 DEBUG::tools.R/processChunks: done
2023-06-06 00:23:46.674886 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.coverage.RData
2023-06-06 00:23:46.676855 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.coverage.bw
2023-06-06 00:23:46.693339 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.summary_coverage.tab
2023-06-06 00:23:46.695288 INFO::coverage.R/calculateCoverage: done
2023-06-06 00:23:46.697741 INFO::analyzeVariants/analyzeVariants: starting ...
2023-06-06 00:23:46.776529 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:23:50.381167 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:23:50.479896 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:23:50.501844 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:23:50.503601 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.raw_variants.RData
2023-06-06 00:23:50.505524 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.filtered_variants.RData
2023-06-06 00:23:50.50704 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-06-06 00:23:50.508326 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-06-06 00:23:50.797361 INFO::analyzeVariants.R/writeVCF: ...done
2023-06-06 00:23:50.921475 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/results/test_pe.summary_variants.tab
2023-06-06 00:23:50.923867 INFO::analyzeVariants/analyzeVariants: done
2023-06-06 00:23:50.927576 INFO::Pipeline run successful.
2023-06-06 00:23:51.111929 INFO::mergeLanes.R/doMergeLanes: starting...
2023-06-06 00:23:51.201777 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:23:51.204774 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.adapter_contaminated_1.RData
2023-06-06 00:23:51.208506 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-06-06 00:23:51.211226 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.adapter_contaminated_2.RData
2023-06-06 00:23:51.226912 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-06-06 00:23:51.230222 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.summary_preprocess.tab
2023-06-06 00:23:51.233185 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-06-06 00:23:51.557017 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-06-06 00:23:51.566785 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.summary_alignment.tab
2023-06-06 00:23:51.578278 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.summary_analyzed_bamstats.tab
2023-06-06 00:23:51.581177 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-06-06 00:23:51.844321 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.summary_target_lengths.tab
2023-06-06 00:23:51.906588 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-06-06 00:23:51.949071 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-06-06 00:23:51.97384 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.counts_exon.tab
2023-06-06 00:23:51.989554 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.counts_exon_disjoint.tab
2023-06-06 00:23:51.999361 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.counts_gene.tab
2023-06-06 00:23:52.007594 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.counts_gene_coding.tab
2023-06-06 00:23:52.015899 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.counts_gene_exonic.tab
2023-06-06 00:23:52.024432 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.counts_intergenic.tab
2023-06-06 00:23:52.040565 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.counts_intron.tab
2023-06-06 00:23:52.04435 INFO::countGenomicFeatures.R/mergeCounts: done
2023-06-06 00:23:52.053237 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.summary_counts.tab
2023-06-06 00:23:52.055789 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-06-06 00:23:52.333718 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-06-06 00:23:54.656665 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.coverage.RData
2023-06-06 00:23:54.659002 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.coverage.bw
2023-06-06 00:23:54.674494 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.summary_coverage.tab
2023-06-06 00:23:54.7156 INFO::analyzeVariants/analyzeVariants: starting ...
2023-06-06 00:23:54.79299 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:23:58.292524 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:23:58.392145 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:23:58.414141 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:23:58.416099 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.raw_variants.RData
2023-06-06 00:23:58.418607 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.filtered_variants.RData
2023-06-06 00:23:58.420653 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-06-06 00:23:58.422221 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-06-06 00:23:58.756971 INFO::analyzeVariants.R/writeVCF: ...done
2023-06-06 00:23:58.891571 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.mergeLanes.3983df3e1d927d/merged/results/merged.summary_variants.tab
2023-06-06 00:23:58.894283 INFO::analyzeVariants/analyzeVariants: done
2023-06-06 00:23:58.89744 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
done successfully.
Executing test function test.markDuplicates ... Timing stopped at: 0 0 0.001
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/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:23:59.241132 INFO::preprocessReads.R/preprocessReads: starting...
2023-06-06 00:23:59.263594 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:23:59.28352 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-06-06 00:23:59.286498 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:24:04.510711 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:24:04.51286 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/chunks/chunk_000001/logs/progress.log
2023-06-06 00:24:07.293418 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-06-06 00:24:07.368475 DEBUG::tools.R/processChunks: done
2023-06-06 00:24:07.371479 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:24:07.373536 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/results/test_pe.adapter_contaminated_1.RData
2023-06-06 00:24:07.37583 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-06-06 00:24:07.377768 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/results/test_pe.adapter_contaminated_2.RData
2023-06-06 00:24:07.386209 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-06-06 00:24:07.3887 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/results/test_pe.summary_preprocess.tab
2023-06-06 00:24:07.391501 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/bams/processed.aligner_input_1.fastq ...
2023-06-06 00:24:07.397396 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/bams/processed.aligner_input_2.fastq ...
2023-06-06 00:24:07.402906 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/reports/shortReadReport_1 ...
2023-06-06 00:24:09.242377 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.preprocessReads.3983df16a0ef49/reports/shortReadReport_2 ...
2023-06-06 00:24:10.77889 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads.minichunks ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:24:11.097381 INFO::preprocessReads.R/preprocessReads: starting...
2023-06-06 00:24:11.104226 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:24:11.108967 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-06-06 00:24:11.111973 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:24:14.71537 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:24:14.71752 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/chunks/chunk_000001/logs/progress.log
2023-06-06 00:24:17.464057 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-06-06 00:24:17.466254 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/chunks/chunk_000002/logs/progress.log
2023-06-06 00:24:20.203088 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-06-06 00:24:20.204933 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/chunks/chunk_000003/logs/progress.log
2023-06-06 00:24:22.971552 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-06-06 00:24:23.046065 DEBUG::tools.R/processChunks: done
2023-06-06 00:24:23.050079 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:24:23.052598 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/results/test_pe.adapter_contaminated_1.RData
2023-06-06 00:24:23.055599 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-06-06 00:24:23.057808 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/results/test_pe.adapter_contaminated_2.RData
2023-06-06 00:24:23.069137 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-06-06 00:24:23.071975 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/results/test_pe.summary_preprocess.tab
2023-06-06 00:24:23.075648 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/bams/processed.aligner_input_1.fastq ...
2023-06-06 00:24:23.082393 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/bams/processed.aligner_input_2.fastq ...
2023-06-06 00:24:23.088033 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/reports/shortReadReport_1 ...
2023-06-06 00:24:24.985431 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.preprocessReads.minichunks.3983df17abff48/reports/shortReadReport_2 ...
2023-06-06 00:24:26.547656 INFO::preprocessReads.R/preprocessReads: done
done successfully.
Executing test function test.preprocessReads_single_end ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:24:26.804975 INFO::preprocessReads.R/preprocessReads: starting...
2023-06-06 00:24:26.827819 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-06-06 00:24:26.830883 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:24:30.348007 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:24:30.350102 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpm9hAgx/test.preprocessReads_single_end.3983df4d92756/chunks/chunk_000001/logs/progress.log
2023-06-06 00:24:32.798798 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2023-06-06 00:24:32.857097 DEBUG::tools.R/processChunks: done
2023-06-06 00:24:32.860583 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:24:32.863192 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads_single_end.3983df4d92756/results/test_se.adapter_contaminated_1.RData
2023-06-06 00:24:32.871842 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-06-06 00:24:32.87436 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.preprocessReads_single_end.3983df4d92756/results/test_se.summary_preprocess.tab
2023-06-06 00:24:32.87702 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpm9hAgx/test.preprocessReads_single_end.3983df4d92756/bams/processed.aligner_input_1.fastq ...
2023-06-06 00:24:32.882437 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpm9hAgx/test.preprocessReads_single_end.3983df4d92756/reports/shortReadReport_1 ...
2023-06-06 00:24:34.76433 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/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:24:35.506535 INFO::preprocessReads.R/preprocessReads: starting...
2023-06-06 00:24:35.528896 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2023-06-06 00:24:35.553586 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2023-06-06 00:24:35.556903 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:24:39.748631 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:24:39.750882 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-06-06 00:24:42.794813 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2023-06-06 00:24:42.87025 DEBUG::tools.R/processChunks: done
2023-06-06 00:24:42.875741 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-06-06 00:24:42.877826 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2023-06-06 00:24:42.880064 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-06-06 00:24:42.881947 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2023-06-06 00:24:42.890019 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-06-06 00:24:42.892496 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2023-06-06 00:24:42.895375 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2023-06-06 00:24:42.90201 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2023-06-06 00:24:42.908565 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2023-06-06 00:24:44.947239 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2023-06-06 00:24:46.697633 INFO::preprocessReads.R/preprocessReads: done
2023-06-06 00:24:46.772989 INFO::alignReads.R/alignReads: starting alignment...
2023-06-06 00:24:46.778241 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:24:51.67118 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:24:51.673635 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-06-06 00:24:57.547668 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.098 minutes
2023-06-06 00:24:57.551225 DEBUG::tools.R/processChunks: done
2023-06-06 00:24:57.553264 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2023-06-06 00:24:57.588426 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-06-06 00:24:57.596727 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2023-06-06 00:24:57.603997 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2023-06-06 00:24:57.606606 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-06-06 00:24:57.790196 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2023-06-06 00:24:57.848713 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-06-06 00:24:57.850059 INFO::alignReads.R/alignReads: done
2023-06-06 00:24:57.927657 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-06-06 00:24:57.946619 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:25:01.561406 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:25:01.563615 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-06-06 00:25:04.175268 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-06-06 00:25:04.178815 DEBUG::tools.R/processChunks: done
2023-06-06 00:25:04.181165 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-06-06 00:25:04.194003 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2023-06-06 00:25:04.204636 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2023-06-06 00:25:04.212742 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2023-06-06 00:25:04.218559 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2023-06-06 00:25:04.224431 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2023-06-06 00:25:04.230045 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2023-06-06 00:25:04.23859 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2023-06-06 00:25:04.242796 INFO::countGenomicFeatures.R/mergeCounts: done
2023-06-06 00:25:04.248061 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2023-06-06 00:25:04.250553 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-06-06 00:25:04.51899 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-06-06 00:25:04.520243 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-06-06 00:25:04.59622 INFO::coverage.R/calculateCoverage: starting...
2023-06-06 00:25:04.600574 DEBUG::tools.R/processChunks: starting...
2023-06-06 00:25:08.116473 DEBUG::tools.R/processChunks: waiting for chunkid=[ ] ...
2023-06-06 00:25:08.118781 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-06-06 00:25:10.478679 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2023-06-06 00:25:10.482013 DEBUG::tools.R/processChunks: done
2023-06-06 00:25:12.247795 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2023-06-06 00:25:12.249898 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2023-06-06 00:25:12.351323 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2023-06-06 00:25:12.353147 INFO::coverage.R/calculateCoverage: done
2023-06-06 00:25:12.354841 INFO::analyzeVariants/analyzeVariants: starting ...
2023-06-06 00:25:12.434725 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-06-06 00:25:25.335664 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-06-06 00:25:25.432197 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-06-06 00:25:25.453563 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-06-06 00:25:25.455294 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2023-06-06 00:25:25.45819 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2023-06-06 00:25:25.459857 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-06-06 00:25:25.46115 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-06-06 00:25:25.753713 INFO::analyzeVariants.R/writeVCF: ...done
2023-06-06 00:25:25.882431 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2023-06-06 00:25:25.885069 INFO::analyzeVariants/analyzeVariants: done
2023-06-06 00:25:25.89076 INFO::Pipeline run successful.
done successfully.
Executing test function test.calculateTargetLength ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpm9hAgx/tp53-config.txt
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/config/default-config.txt
2023-06-06 00:25:26.194591 INFO::io.R/saveWithID: saving file= /tmp/Rtmpm9hAgx/test.calcTargetLengths.3983df700eabfb/results/test_pe.summary_target_lengths.tab
done successfully.
Executing test function test.sclapply ... done successfully.
Executing test function test.tryKeepTraceback ... done successfully.
Executing test function test.truncateReads ... done successfully.
Executing test function test.truncateReads.trim5 ... done successfully.
RUNIT TEST PROTOCOL -- Tue Jun 6 00:25:40 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/R/R-4.3.0/site-library/HTSeqGenie/unitTests
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.alignReads.R
test.alignReads: (2 checks) ... OK (30.73 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (19.78 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.55 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (82.66 seconds)
test.wrap.callVariants: (4 checks) ... OK (12.31 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (24.2 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (3.04 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.17 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.68 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.bamUtils.R
test.isFirstFragment: (5 checks) ... OK (0 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R
test.buildCountsGRangesList: (3 checks) ... OK (37.67 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (30.77 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R
test.computeCoverage: (9 checks) ... OK (1.03 seconds)
test.isSparse: (5 checks) ... OK (0.14 seconds)
test.mergeCoverage: (1 checks) ... OK (1.9 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.4 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.checkConfig.R
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.21 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.config.R
test.checkConfig: (5 checks) ... OK (0.42 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.51 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/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R
test.getAdapterSeqs: (5 checks) ... OK (0.05 seconds)
test.isAdapter: (5 checks) ... OK (0.16 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.12 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R
test.detectRRNA: (1 checks) ... OK (0.33 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.47 seconds)
test.getRRNAIds: (1 checks) ... OK (0.28 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.19 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.filterQuality.R
test.filterByLength: (2 checks) ... OK (0.09 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.07 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.06 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/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.22 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.io.R
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.22 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.4 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (1.47 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.2 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.71 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.16 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.24 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R
test.mergeLanes: (6 checks) ... OK (65.36 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/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/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R
test.preprocessReads: (5 checks) ... OK (11.78 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.77 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.22 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R
test.readRNASeqEnds: (6 checks) ... OK (0.11 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.18 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.14 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.05 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.runPipeline.R
test.runPipeline: (1 checks) ... OK (50.64 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.targetLengths.R
test.calculateTargetLength: (4 checks) ... OK (0.3 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.tools.R
test.sclapply: (10 checks) ... OK (13.78 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
---------------------------
Test file: /home/biocbuild/R/R-4.3.0/site-library/HTSeqGenie/unitTests/runit.trimReads.R
test.truncateReads: (7 checks) ... OK (0.08 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.24 seconds)
runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
>
> proc.time()
user system elapsed
320.872 75.902 442.390
HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings
| name | user | system | elapsed | |
| HTSeqGenie | 0 | 0 | 0 | |
| buildGenomicFeaturesFromTxDb | 0 | 0 | 0 | |
| runPipeline | 0.001 | 0.000 | 0.001 | |