Back to Build/check report for BioC 3.18:   simplified   long
ABCDEFG[H]IJKLMNOPQRSTUVWXYZ

This page was generated on 2023-05-10 10:04:33 -0000 (Wed, 10 May 2023).

HostnameOSArch (*)R versionInstalled pkgs
kunpeng1Linux (Ubuntu 22.04.1 LTS)aarch64R Under development (unstable) (2023-03-12 r83975) -- "Unsuffered Consequences" 6211
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

CHECK results for HTSeqGenie on kunpeng1


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.

raw results

Package 936/2194HostnameOS / ArchINSTALLBUILDCHECKBUILD BIN
HTSeqGenie 4.31.0  (landing page)
Jens Reeder
Snapshot Date: 2023-05-08 19:11:19 -0000 (Mon, 08 May 2023)
git_url: https://git.bioconductor.org/packages/HTSeqGenie
git_branch: devel
git_last_commit: 6787c4b
git_last_commit_date: 2023-04-25 14:24:28 -0000 (Tue, 25 Apr 2023)
kunpeng1Linux (Ubuntu 22.04.1 LTS) / aarch64  OK    OK    OK  

Summary

Package: HTSeqGenie
Version: 4.31.0
Command: /home/biocbuild/bbs-3.17-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.17-bioc/R/site-library --timings HTSeqGenie_4.31.0.tar.gz
StartedAt: 2023-05-09 18:39:45 -0000 (Tue, 09 May 2023)
EndedAt: 2023-05-09 18:58:24 -0000 (Tue, 09 May 2023)
EllapsedTime: 1118.5 seconds
RetCode: 0
Status:   OK  
CheckDir: HTSeqGenie.Rcheck
Warnings: 0

Command output

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/bbs-3.17-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.17-bioc/R/site-library --timings HTSeqGenie_4.31.0.tar.gz
###
##############################################################################
##############################################################################


* using log directory ‘/home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck’
* using R Under development (unstable) (2023-03-12 r83975)
* using platform: aarch64-unknown-linux-gnu (64-bit)
* R was compiled by
    gcc (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0
    GNU Fortran (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0
* running under: Ubuntu 22.04.2 LTS
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.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 startup messages can be suppressed ... OK
* checking dependencies in R code ... NOTE
Unexported objects imported by ':::' calls:
  ‘ShortRead:::.set_omp_threads’ ‘gmapR:::..gsnap’ ‘gmapR:::GeneGenome’
  ‘gmapR:::checkPackageInstalled’ ‘gmapR:::getDefaultGmapGenomePath’
  ‘gmapR:::getGeneRoi’ ‘gmapR:::subsetRegion’ ‘parallel:::mckill’
  See the note in ?`:::` about the use of this operator.
* checking S3 generic/method consistency ... OK
* checking replacement functions ... OK
* checking foreign function calls ... NOTE
Foreign function call to a different package:
  .Call(ShortRead:::.set_omp_threads, ...)
See chapter ‘System and foreign language interfaces’ in the ‘Writing R
Extensions’ manual.
* checking R code for possible problems ... NOTE
.makePreprocessAlignPlots: no visible binding for global variable
  ‘data’
.plot.in.out.min.max.readlength: no visible global function definition
  for ‘median’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.lfqs’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.chunkid’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.subsampling_filter’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.max_nbchunks’
addHandler: no visible binding for '<<-' assignment to
  ‘logging.handlers’
addHandler: no visible binding for global variable ‘logging.handlers’
addHandler: no visible binding for '<<-' assignment to ‘logging.file’
buildAnyFastaGenome: no visible global function definition for ‘getSeq’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘gaps’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘ranges’
buildTP53FastaGenome: no visible global function definition for
  ‘getSeq’
buildTallyParam: no visible global function definition for ‘seqinfo’
computeCoverage: no visible global function definition for ‘resize’
computeCoverage: no visible global function definition for ‘coverage’
estimateCutoffs : <anonymous>: no visible binding for global variable
  ‘quantile’
getGenomeSegments: no visible global function definition for ‘seqinfo’
hashVariants: no visible global function definition for ‘ranges’
isAboveQualityThresh: no visible global function definition for ‘Views’
isAboveQualityThresh: no visible global function definition for
  ‘viewMeans’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.n’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.x’
logReset: no visible binding for '<<-' assignment to ‘logging.handlers’
logReset: no visible binding for '<<-' assignment to ‘logging.loglevel’
logReset: no visible binding for '<<-' assignment to ‘logging.file’
loglevel: no visible binding for global variable ‘logging.loglevel’
loglevel: no visible binding for global variable ‘logging.handlers’
processChunks : tracefun: no visible binding for global variable
  ‘sjobs’
processChunks : tracefun: no visible binding for global variable
  ‘chunkid’
setLevel: no visible binding for '<<-' assignment to ‘logging.loglevel’
statCountFeatures: no visible global function definition for ‘quantile’
truncateReads: no visible global function definition for ‘subseq’
vcfStat: no visible global function definition for ‘quantile’
writeToFile: no visible binding for global variable ‘logging.file’
Undefined global functions or variables:
  Views chunkid coverage data gaps getSeq logging.file logging.handlers
  logging.loglevel median quantile ranges resize seqinfo sjobs subseq
  viewMeans
Consider adding
  importFrom("stats", "median", "quantile")
  importFrom("utils", "data")
to your NAMESPACE file.
* checking Rd files ... OK
* checking Rd metadata ... OK
* checking Rd cross-references ... OK
* checking for missing documentation entries ... OK
* checking for code/documentation mismatches ... OK
* checking Rd \usage sections ... OK
* checking Rd contents ... OK
* checking for unstated dependencies in examples ... OK
* checking files in ‘vignettes’ ... OK
* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
  Running ‘doRUnit.R’
 OK
* checking for unstated dependencies in vignettes ... OK
* checking package vignettes in ‘inst/doc’ ... OK
* checking running R code from vignettes ...
  ‘HTSeqGenie.Rnw’... OK
 OK
* checking re-building of vignette outputs ... OK
* checking PDF version of manual ... OK
* DONE

Status: 5 NOTEs
See
  ‘/home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck/00check.log’
for details.

Installation output

HTSeqGenie.Rcheck/00install.out

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/bbs-3.17-bioc/R/bin/R CMD INSTALL HTSeqGenie
###
##############################################################################
##############################################################################


* installing to library ‘/home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library’
* installing *source* package ‘HTSeqGenie’ ...
** using staged installation
** R
** inst
** byte-compile and prepare package for lazy loading
** help
*** installing help indices
** building package indices
** installing vignettes
** testing if installed package can be loaded from temporary location
** testing if installed package can be loaded from final location
** testing if installed package keeps a record of temporary installation path
* DONE (HTSeqGenie)

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R Under development (unstable) (2023-03-12 r83975) -- "Unsuffered Consequences"
Copyright (C) 2023 The R Foundation for Statistical Computing
Platform: aarch64-unknown-linux-gnu (64-bit)

R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.

R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.

Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.

> library("HTSeqGenie")
Loading required package: gmapR
Loading required package: GenomeInfoDb
Loading required package: BiocGenerics

Attaching package: 'BiocGenerics'

The following objects are masked from 'package:stats':

    IQR, mad, sd, var, xtabs

The following objects are masked from 'package:base':

    Filter, Find, Map, Position, Reduce, anyDuplicated, aperm, append,
    as.data.frame, basename, cbind, colnames, dirname, do.call,
    duplicated, eval, evalq, get, grep, grepl, intersect, is.unsorted,
    lapply, mapply, match, mget, order, paste, pmax, pmax.int, pmin,
    pmin.int, rank, rbind, rownames, sapply, setdiff, sort, table,
    tapply, union, unique, unsplit, which.max, which.min

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

The following objects are masked from 'package:base':

    I, expand.grid, unname

Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector

Attaching package: 'Biostrings'

The following object is masked from 'package:base':

    strsplit

Loading required package: ShortRead
Loading required package: BiocParallel
Loading required package: GenomicAlignments
Loading required package: SummarizedExperiment
Loading required package: MatrixGenerics
Loading required package: matrixStats

Attaching package: 'MatrixGenerics'

The following objects are masked from 'package:matrixStats':

    colAlls, colAnyNAs, colAnys, colAvgsPerRowSet, colCollapse,
    colCounts, colCummaxs, colCummins, colCumprods, colCumsums,
    colDiffs, colIQRDiffs, colIQRs, colLogSumExps, colMadDiffs,
    colMads, colMaxs, colMeans2, colMedians, colMins, colOrderStats,
    colProds, colQuantiles, colRanges, colRanks, colSdDiffs, colSds,
    colSums2, colTabulates, colVarDiffs, colVars, colWeightedMads,
    colWeightedMeans, colWeightedMedians, colWeightedSds,
    colWeightedVars, rowAlls, rowAnyNAs, rowAnys, rowAvgsPerColSet,
    rowCollapse, rowCounts, rowCummaxs, rowCummins, rowCumprods,
    rowCumsums, rowDiffs, rowIQRDiffs, rowIQRs, rowLogSumExps,
    rowMadDiffs, rowMads, rowMaxs, rowMeans2, rowMedians, rowMins,
    rowOrderStats, rowProds, rowQuantiles, rowRanges, rowRanks,
    rowSdDiffs, rowSds, rowSums2, rowTabulates, rowVarDiffs, rowVars,
    rowWeightedMads, rowWeightedMeans, rowWeightedMedians,
    rowWeightedSds, rowWeightedVars

Loading required package: Biobase
Welcome to Bioconductor

    Vignettes contain introductory material; view with
    'browseVignettes()'. To cite Bioconductor, see
    'citation("Biobase")', and for packages 'citation("pkgname")'.


Attaching package: 'Biobase'

The following object is masked from 'package:MatrixGenerics':

    rowMedians

The following objects are masked from 'package:matrixStats':

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

The following object is masked from 'package:base':

    tabulate

> 
> source(getPackageFile("unitTests/runTests.R"))
Loading required package: GenomicFeatures
Loading required package: AnnotationDbi
did not source anything in dirname= ./R 


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:47:03.212194 INFO::preprocessReads.R/preprocessReads: starting...
2023-05-09 18:47:03.223125 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:47:03.228618 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-05-09 18:47:03.231688 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:47:07.111615 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:47:07.113706 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/chunks/chunk_000001/logs/progress.log
2023-05-09 18:47:10.028515 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2023-05-09 18:47:10.03096 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/chunks/chunk_000002/logs/progress.log
2023-05-09 18:47:12.953872 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.049 minutes
2023-05-09 18:47:12.95565 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/chunks/chunk_000003/logs/progress.log
2023-05-09 18:47:15.853507 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2023-05-09 18:47:15.895281 DEBUG::tools.R/processChunks: done
2023-05-09 18:47:15.900465 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:47:15.903675 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/results/test_pe.adapter_contaminated_1.RData
2023-05-09 18:47:15.907793 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-05-09 18:47:15.91036 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/results/test_pe.adapter_contaminated_2.RData
2023-05-09 18:47:15.923291 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-05-09 18:47:15.926476 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/results/test_pe.summary_preprocess.tab
2023-05-09 18:47:15.931118 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/bams/processed.aligner_input_1.fastq ...
2023-05-09 18:47:15.937206 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/bams/processed.aligner_input_2.fastq ...
2023-05-09 18:47:15.942524 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/reports/shortReadReport_1 ...
2023-05-09 18:47:17.821046 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/reports/shortReadReport_2 ...
2023-05-09 18:47:21.110599 INFO::preprocessReads.R/preprocessReads: done
2023-05-09 18:47:21.168712 INFO::alignReads.R/alignReads: starting alignment...
2023-05-09 18:47:21.176649 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:47:25.114192 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:47:25.117007 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/chunks/chunk_000001/logs/progress.log
2023-05-09 18:47:28.186169 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2023-05-09 18:47:28.18833 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/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-05-09 18:47:30.980081 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-05-09 18:47:30.982667 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/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-05-09 18:47:33.765462 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2023-05-09 18:47:33.768711 DEBUG::tools.R/processChunks: done
2023-05-09 18:47:33.770781 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-05-09 18:47:34.082479 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-05-09 18:47:34.094172 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/results/test_pe.summary_alignment.tab
2023-05-09 18:47:34.104902 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/results/test_pe.summary_analyzed_bamstats.tab
2023-05-09 18:47:34.107349 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-05-09 18:47:34.410519 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.4071f224cacfd/results/test_pe.summary_target_lengths.tab
2023-05-09 18:47:34.471695 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-05-09 18:47:34.473086 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:47:34.829271 INFO::preprocessReads.R/preprocessReads: starting...
2023-05-09 18:47:34.833229 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:47:34.936538 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2023-05-09 18:47:34.943046 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:47:34.947132 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-05-09 18:47:34.94973 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:47:38.75158 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:47:38.753889 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/chunks/chunk_000001/logs/progress.log
2023-05-09 18:47:41.62125 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2023-05-09 18:47:41.623078 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/chunks/chunk_000002/logs/progress.log
2023-05-09 18:47:44.461553 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2023-05-09 18:47:44.463423 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/chunks/chunk_000003/logs/progress.log
2023-05-09 18:47:47.414592 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2023-05-09 18:47:47.416857 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/chunks/chunk_000004/logs/progress.log
2023-05-09 18:47:50.247787 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.047 minutes
2023-05-09 18:47:50.288513 DEBUG::tools.R/processChunks: done
2023-05-09 18:47:50.293252 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:47:50.296625 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/results/test_pe.adapter_contaminated_1.RData
2023-05-09 18:47:50.301153 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-05-09 18:47:50.303856 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/results/test_pe.adapter_contaminated_2.RData
2023-05-09 18:47:50.318546 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-05-09 18:47:50.32179 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/results/test_pe.summary_preprocess.tab
2023-05-09 18:47:50.326921 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/bams/processed.aligner_input_1.fastq ...
2023-05-09 18:47:50.333356 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/bams/processed.aligner_input_2.fastq ...
2023-05-09 18:47:50.338085 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/reports/shortReadReport_1 ...
2023-05-09 18:47:52.133053 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.alignReads.sparsechunks.4071f166c6d56/reports/shortReadReport_2 ...
2023-05-09 18:47:55.040485 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:47:55.272964 INFO::alignReads.R/alignReadsChunk: running gsnap...
2023-05-09 18:47:55.278927 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/Rtmpft32Hq/test.alignReadsOneSingleEnd.4071f6ef672aa/bams/test.alignReads /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2023-05-09 18:47:55.508501 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2023-05-09 18:47:55.637584 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReadsOneSingleEnd.4071f6ef672aa/results/test.alignReads.summary_alignment.tab
2023-05-09 18:47:55.696665 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.alignReadsOneSingleEnd.4071f6ef672aa/results/test.alignReads.summary_analyzed_bamstats.tab
2023-05-09 18:47:55.699386 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.002 0 0.003
Error in DEACTIVATED("Skipped annotateVariants() test") : 
  Skipped annotateVariants() test
In addition: There were 11 warnings (use warnings() to see them)
 done successfully.



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:47:56.125594 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.genotype.4071fa8ec9b4/results/test_pe.coverage.RData
2023-05-09 18:47:56.127981 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpft32Hq/test.genotype.4071fa8ec9b4/results/test_pe.coverage.bw
2023-05-09 18:47:56.312998 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.genotype.4071fa8ec9b4/results/test_pe.summary_coverage.tab
2023-05-09 18:47:56.315344 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:48:08.762816 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:48:08.877984 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:48:08.900223 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:48:08.90223 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.genotype.4071fa8ec9b4/results/test_pe.raw_variants.RData
2023-05-09 18:48:08.905757 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.genotype.4071fa8ec9b4/results/test_pe.filtered_variants.RData
2023-05-09 18:48:08.91009 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-05-09 18:48:08.911786 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-05-09 18:48:09.476387 INFO::analyzeVariants.R/writeVCF: ...done
2023-05-09 18:48:09.478144 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2023-05-09 18:49:13.092392 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-05-09 18:49:13.651951 INFO::analyzeVariants.R/writeVCF: ...done
2023-05-09 18:49:13.653159 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/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:49:14.190475 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:49:25.26066 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:49:25.350078 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:49:25.369992 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:49:25.371601 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.4071fa782376/results/test_pe.raw_variants.RData
2023-05-09 18:49:25.374686 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.4071fa782376/results/test_pe.filtered_variants.RData
2023-05-09 18:49:25.376281 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:49:25.54496 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:49:36.420086 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:49:36.493441 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:49:36.515218 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:49:36.516997 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.filters.4071f25d0aafd/results/test_pe.raw_variants.RData
2023-05-09 18:49:36.520262 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.filters.4071f25d0aafd/results/test_pe.filtered_variants.RData
2023-05-09 18:49:36.521947 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-05-09 18:49:36.523552 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:49:47.206844 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:49:47.254054 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:49:47.27501 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:49:47.276679 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.filters.4071f25d0aafd/results/test_pe.raw_variants.RData
2023-05-09 18:49:47.280086 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.filters.4071f25d0aafd/results/test_pe.filtered_variants.RData
2023-05-09 18:49:47.283 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:49:47.482765 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:49:47.48479 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2023-05-09 18:49:50.030567 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:49:50.121725 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:49:50.142609 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:49:50.144232 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.which.4071f485c60cb/results/test_pe.raw_variants.RData
2023-05-09 18:49:50.146228 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.wrap.callVariants.which.4071f485c60cb/results/test_pe.filtered_variants.RData
2023-05-09 18:49:50.14781 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:49:50.324881 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-05-09 18:49:50.326495 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:49:50.562114 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-05-09 18:49:50.848406 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-05-09 18:51:02.746468 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/nwaejofk/merged/results/bla.coverage.RData
2023-05-09 18:51:02.749666 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpft32Hq/nwaejofk/merged/results/bla.coverage.bw
2023-05-09 18:51:02.866432 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/nwaejofk/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2023-05-09 18:51:04.190494 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/gihuzosa/merged/results/bla.coverage.RData
2023-05-09 18:51:04.192837 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpft32Hq/gihuzosa/merged/results/bla.coverage.bw
2023-05-09 18:51:04.206981 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/gihuzosa/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.findTemplate  ...  done successfully.



Executing test function test.checkConfig  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.getConfig  ...  done successfully.



Executing test function test.loadConfig  ...  done successfully.



Executing test function test.parseDCF  ...  done successfully.



Executing test function test.updateConfig  ...  done successfully.



Executing test function test.getAdapterSeqs  ...  done successfully.



Executing test function test.isAdapter  ...  done successfully.



Executing test function test.isAdapter3.primeEnd  ...  done successfully.



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:05.939639 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-05-09 18:51:05.941233 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpft32Hq/test.detectRRNA.4071f1065fc1e/bams/rRNA_contam/input1.fastq
2023-05-09 18:51:05.945904 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/Rtmpft32Hq/test.detectRRNA.4071f1065fc1e/bams/rRNA_contam/test_se /tmp/Rtmpft32Hq/test.detectRRNA.4071f1065fc1e/bams/rRNA_contam/input1.fastq 2>&1
2023-05-09 18:51:06.102092 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-05-09 18:51:06.103559 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:06.33145 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2023-05-09 18:51:06.333793 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpft32Hq/test.detectRRNA.paired_end.4071f79a10da3/bams/rRNA_contam/input1.fastq
2023-05-09 18:51:06.335933 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpft32Hq/test.detectRRNA.paired_end.4071f79a10da3/bams/rRNA_contam/input2.fastq
2023-05-09 18:51:06.339014 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/Rtmpft32Hq/test.detectRRNA.paired_end.4071f79a10da3/bams/rRNA_contam/test_pe /tmp/Rtmpft32Hq/test.detectRRNA.paired_end.4071f79a10da3/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmpft32Hq/test.detectRRNA.paired_end.4071f79a10da3/bams/rRNA_contam/input2.fastq 2>&1
2023-05-09 18:51:06.632282 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2023-05-09 18:51:06.633709 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2023-05-09 18:51:06.6613 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/Rtmpft32Hq/test_get_rRNA_idshuoifmqk/test_pe /tmp/Rtmpft32Hq/test_get_rRNA_idshuoifmqk/1.fastq -a paired /tmp/Rtmpft32Hq/test_get_rRNA_idshuoifmqk/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2023-05-09 18:51:06.983141 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/Rtmpft32Hq/test_get_rRNAIds_randomivaorxky/test_pe /tmp/Rtmpft32Hq/test_get_rRNAIds_randomivaorxky/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2023-05-09 18:51:07.214434 INFO::filterQuality.R/filterQuality: filterByLength...
2023-05-09 18:51:07.216466 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2023-05-09 18:51:07.217803 INFO::filterQuality.R/filterByLength: done
2023-05-09 18:51:07.284893 INFO::filterQuality.R/filterQuality: filterByLength...
2023-05-09 18:51:07.286203 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2023-05-09 18:51:07.287457 INFO::filterQuality.R/filterByLength: done
 done successfully.



Executing test function test.isAboveQualityThresh  ...  done successfully.



Executing test function test.trimTailsByQuality  ... 2023-05-09 18:51:07.361091 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-05-09 18:51:07.373845 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-05-09 18:51:07.375415 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-05-09 18:51:07.381962 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-05-09 18:51:07.3835 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-05-09 18:51:07.390046 INFO::preprocessReads.R/preprocessReadsChunk: done
2023-05-09 18:51:07.39158 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2023-05-09 18:51:07.398114 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



Executing test function test.callVariantsGATK  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") : 
  callVariantsGATK() tests need gatk.path option set
In addition: There were 50 or more warnings (use warnings() to see the first 50)
 done successfully.



Executing test function test.callVariantsGATK.withFiltering  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") : 
  callVariantsGATK() tests need gatk.path option set
 done successfully.



Executing test function test.checkGATKJar  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") : 
  checkGATKJar() test needs gatk.path option set
 done successfully.



Executing test function test.excludeVariantsByRegion  ...  done successfully.



Executing test function test.gatk  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("gatk() tests need gatk.path option set") : 
  gatk() tests need gatk.path option set
 done successfully.



Executing test function test.realignIndels  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("test.realignIndels() tests need gatk.path option set") : 
  test.realignIndels() tests need gatk.path option set
 done successfully.



Executing test function test.realignIndelsGATK  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") : 
  realignIndelsGATK() tests need gatk.path option set
 done successfully.



Executing test function test.realignIndelsGATK.parallel  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") : 
  realignIndelsGATK() tests need gatk.path option set
 done successfully.



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:07.783124 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:07.786274 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.pefq.subsample  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:08.063791 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:08.180553 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-05-09 18:51:08.184351 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:08.18742 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:08.496083 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:08.711911 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:08.915707 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:08.990265 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-05-09 18:51:08.99369 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:08.996853 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:09.27617 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:09.34986 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2023-05-09 18:51:09.353284 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:09.356388 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.createTmpDir  ...  done successfully.



Executing test function test.detectQualityInFASTQFile  ...  done successfully.



Executing test function test.getObjectFilename  ...  done successfully.



Executing test function test.safeUnlink  ...  done successfully.



Executing test function test.writeAudit  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:51:10.356128 INFO::preprocessReads.R/preprocessReads: starting...
2023-05-09 18:51:10.363395 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:51:10.368505 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-05-09 18:51:10.372059 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:51:13.902465 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:51:13.904481 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000001/logs/progress.log
2023-05-09 18:51:16.699991 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-05-09 18:51:16.702018 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000002/logs/progress.log
2023-05-09 18:51:19.462801 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-05-09 18:51:19.46512 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000003/logs/progress.log
2023-05-09 18:51:22.261108 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2023-05-09 18:51:22.33159 DEBUG::tools.R/processChunks: done
2023-05-09 18:51:22.335404 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:51:22.337878 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.adapter_contaminated_1.RData
2023-05-09 18:51:22.340985 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-05-09 18:51:22.343328 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.adapter_contaminated_2.RData
2023-05-09 18:51:22.354805 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-05-09 18:51:22.357539 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.summary_preprocess.tab
2023-05-09 18:51:22.36127 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/bams/processed.aligner_input_1.fastq ...
2023-05-09 18:51:22.367693 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/bams/processed.aligner_input_2.fastq ...
2023-05-09 18:51:22.372819 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/reports/shortReadReport_1 ...
2023-05-09 18:51:24.239398 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/reports/shortReadReport_2 ...
2023-05-09 18:51:25.742138 INFO::preprocessReads.R/preprocessReads: done
2023-05-09 18:51:25.820637 INFO::alignReads.R/alignReads: starting alignment...
2023-05-09 18:51:25.827167 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:51:30.785607 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:51:30.787984 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000001/logs/progress.log
2023-05-09 18:51:33.505482 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2023-05-09 18:51:33.507661 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/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-05-09 18:51:36.240466 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-05-09 18:51:36.242766 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/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-05-09 18:51:38.956692 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2023-05-09 18:51:38.959953 DEBUG::tools.R/processChunks: done
2023-05-09 18:51:38.96191 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-05-09 18:51:39.242226 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-05-09 18:51:39.252955 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.summary_alignment.tab
2023-05-09 18:51:39.263658 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.summary_analyzed_bamstats.tab
2023-05-09 18:51:39.266431 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-05-09 18:51:39.547187 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.summary_target_lengths.tab
2023-05-09 18:51:39.608604 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-05-09 18:51:39.609976 INFO::alignReads.R/alignReads: done
2023-05-09 18:51:39.691022 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-05-09 18:51:39.716817 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:51:43.302942 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:51:43.305184 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000001/logs/progress.log
2023-05-09 18:51:45.864174 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2023-05-09 18:51:45.866457 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000002/logs/progress.log
2023-05-09 18:51:48.436722 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2023-05-09 18:51:48.438877 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000003/logs/progress.log
2023-05-09 18:51:51.018889 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2023-05-09 18:51:51.022422 DEBUG::tools.R/processChunks: done
2023-05-09 18:51:51.024666 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-05-09 18:51:51.042094 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.counts_exon.tab
2023-05-09 18:51:51.055913 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.counts_exon_disjoint.tab
2023-05-09 18:51:51.065324 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.counts_gene.tab
2023-05-09 18:51:51.072693 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.counts_gene_coding.tab
2023-05-09 18:51:51.079992 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.counts_gene_exonic.tab
2023-05-09 18:51:51.087414 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.counts_intergenic.tab
2023-05-09 18:51:51.099174 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.counts_intron.tab
2023-05-09 18:51:51.102842 INFO::countGenomicFeatures.R/mergeCounts: done
2023-05-09 18:51:51.110475 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.summary_counts.tab
2023-05-09 18:51:51.112716 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-05-09 18:51:51.461633 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-05-09 18:51:51.462818 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-05-09 18:51:51.545204 INFO::coverage.R/calculateCoverage: starting...
2023-05-09 18:51:51.55112 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:51:55.377133 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:51:55.379342 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000001/logs/progress.log
2023-05-09 18:51:57.591309 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2023-05-09 18:51:57.593667 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000002/logs/progress.log
2023-05-09 18:51:59.801163 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2023-05-09 18:51:59.803375 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/chunks/chunk_000003/logs/progress.log
2023-05-09 18:52:02.018686 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2023-05-09 18:52:02.022401 DEBUG::tools.R/processChunks: done
2023-05-09 18:52:03.97033 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.coverage.RData
2023-05-09 18:52:03.97227 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.coverage.bw
2023-05-09 18:52:03.987283 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.summary_coverage.tab
2023-05-09 18:52:03.989146 INFO::coverage.R/calculateCoverage: done
2023-05-09 18:52:03.991734 INFO::analyzeVariants/analyzeVariants: starting ...
2023-05-09 18:52:04.081074 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:52:07.568569 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:52:07.659842 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:52:07.680425 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:52:07.682153 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.raw_variants.RData
2023-05-09 18:52:07.684185 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.filtered_variants.RData
2023-05-09 18:52:07.6863 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-05-09 18:52:07.687639 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-05-09 18:52:07.965552 INFO::analyzeVariants.R/writeVCF: ...done
2023-05-09 18:52:08.084712 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/results/test_pe.summary_variants.tab
2023-05-09 18:52:08.087227 INFO::analyzeVariants/analyzeVariants: done
2023-05-09 18:52:08.091572 INFO::Pipeline run successful.
2023-05-09 18:52:08.296455 INFO::mergeLanes.R/doMergeLanes: starting...
2023-05-09 18:52:08.303491 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:52:08.30728 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.adapter_contaminated_1.RData
2023-05-09 18:52:08.311697 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-05-09 18:52:08.314842 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.adapter_contaminated_2.RData
2023-05-09 18:52:08.330555 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-05-09 18:52:08.333908 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.summary_preprocess.tab
2023-05-09 18:52:08.337095 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-05-09 18:52:08.68491 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-05-09 18:52:08.695223 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.summary_alignment.tab
2023-05-09 18:52:08.70715 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.summary_analyzed_bamstats.tab
2023-05-09 18:52:08.710273 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-05-09 18:52:09.009278 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.summary_target_lengths.tab
2023-05-09 18:52:09.075852 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-05-09 18:52:09.123864 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-05-09 18:52:09.151388 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.counts_exon.tab
2023-05-09 18:52:09.167933 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.counts_exon_disjoint.tab
2023-05-09 18:52:09.178518 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.counts_gene.tab
2023-05-09 18:52:09.187608 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.counts_gene_coding.tab
2023-05-09 18:52:09.195971 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.counts_gene_exonic.tab
2023-05-09 18:52:09.204457 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.counts_intergenic.tab
2023-05-09 18:52:09.220146 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.counts_intron.tab
2023-05-09 18:52:09.22429 INFO::countGenomicFeatures.R/mergeCounts: done
2023-05-09 18:52:09.233912 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.summary_counts.tab
2023-05-09 18:52:09.236696 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-05-09 18:52:09.515917 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-05-09 18:52:12.300815 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.coverage.RData
2023-05-09 18:52:12.303956 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.coverage.bw
2023-05-09 18:52:12.319689 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.summary_coverage.tab
2023-05-09 18:52:12.364553 INFO::analyzeVariants/analyzeVariants: starting ...
2023-05-09 18:52:12.451725 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:52:16.033163 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:52:16.120357 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:52:16.140091 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:52:16.141794 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.raw_variants.RData
2023-05-09 18:52:16.143782 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.filtered_variants.RData
2023-05-09 18:52:16.145342 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-05-09 18:52:16.146559 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-05-09 18:52:16.409248 INFO::analyzeVariants.R/writeVCF: ...done
2023-05-09 18:52:16.521558 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.mergeLanes.4071f319cd7eb/merged/results/merged.summary_variants.tab
2023-05-09 18:52:16.523874 INFO::analyzeVariants/analyzeVariants: done
2023-05-09 18:52:16.527219 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0 0 0
Error in DEACTIVATED("Skipped markDuplicates() test") : 
  Skipped markDuplicates() test
In addition: There were 28 warnings (use warnings() to see them)
 done successfully.



Executing test function test.markDuplicates_w_outfile  ... Timing stopped at: 0 0 0.001
Error in DEACTIVATED("Skipped markDuplicates() test") : 
  Skipped markDuplicates() test
 done successfully.



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:52:16.841346 INFO::preprocessReads.R/preprocessReads: starting...
2023-05-09 18:52:16.866197 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:52:16.872008 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-05-09 18:52:16.875083 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:52:20.979909 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:52:20.981896 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/chunks/chunk_000001/logs/progress.log
2023-05-09 18:52:23.794202 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2023-05-09 18:52:23.873779 DEBUG::tools.R/processChunks: done
2023-05-09 18:52:23.876959 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:52:23.879206 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/results/test_pe.adapter_contaminated_1.RData
2023-05-09 18:52:23.881736 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-05-09 18:52:23.883816 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/results/test_pe.adapter_contaminated_2.RData
2023-05-09 18:52:23.892569 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-05-09 18:52:23.895494 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/results/test_pe.summary_preprocess.tab
2023-05-09 18:52:23.898398 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/bams/processed.aligner_input_1.fastq ...
2023-05-09 18:52:23.903751 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/bams/processed.aligner_input_2.fastq ...
2023-05-09 18:52:23.909031 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/reports/shortReadReport_1 ...
2023-05-09 18:52:25.754781 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.preprocessReads.4071f790fa256/reports/shortReadReport_2 ...
2023-05-09 18:52:27.237683 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:52:27.598206 INFO::preprocessReads.R/preprocessReads: starting...
2023-05-09 18:52:27.606706 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:52:27.612247 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2023-05-09 18:52:27.615695 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:52:31.503755 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:52:31.505707 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/chunks/chunk_000001/logs/progress.log
2023-05-09 18:52:34.294174 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2023-05-09 18:52:34.296643 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/chunks/chunk_000002/logs/progress.log
2023-05-09 18:52:37.076603 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2023-05-09 18:52:37.078864 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/chunks/chunk_000003/logs/progress.log
2023-05-09 18:52:39.889081 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2023-05-09 18:52:39.966218 DEBUG::tools.R/processChunks: done
2023-05-09 18:52:39.970375 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:52:39.972652 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/results/test_pe.adapter_contaminated_1.RData
2023-05-09 18:52:39.975499 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-05-09 18:52:39.977629 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/results/test_pe.adapter_contaminated_2.RData
2023-05-09 18:52:39.988363 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-05-09 18:52:39.990968 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/results/test_pe.summary_preprocess.tab
2023-05-09 18:52:39.994466 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/bams/processed.aligner_input_1.fastq ...
2023-05-09 18:52:40.000257 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/bams/processed.aligner_input_2.fastq ...
2023-05-09 18:52:40.005475 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/reports/shortReadReport_1 ...
2023-05-09 18:52:41.768525 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.preprocessReads.minichunks.4071f6a156f2a/reports/shortReadReport_2 ...
2023-05-09 18:52:43.212742 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:52:43.565033 INFO::preprocessReads.R/preprocessReads: starting...
2023-05-09 18:52:43.590951 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2023-05-09 18:52:43.594177 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:52:47.209572 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:52:47.211543 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpft32Hq/test.preprocessReads_single_end.4071f339aa1ff/chunks/chunk_000001/logs/progress.log
2023-05-09 18:52:49.676098 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2023-05-09 18:52:49.732665 DEBUG::tools.R/processChunks: done
2023-05-09 18:52:49.735818 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:52:49.738159 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads_single_end.4071f339aa1ff/results/test_se.adapter_contaminated_1.RData
2023-05-09 18:52:49.746436 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-05-09 18:52:49.748716 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.preprocessReads_single_end.4071f339aa1ff/results/test_se.summary_preprocess.tab
2023-05-09 18:52:49.7512 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpft32Hq/test.preprocessReads_single_end.4071f339aa1ff/bams/processed.aligner_input_1.fastq ...
2023-05-09 18:52:49.756004 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpft32Hq/test.preprocessReads_single_end.4071f339aa1ff/reports/shortReadReport_1 ...
2023-05-09 18:52:51.508006 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.readRNASeqEnds  ...  done successfully.



Executing test function test.readRNASeqEnds.dupmark  ...  done successfully.



Executing test function test.how_many  ...  done successfully.



Executing test function test.plotDF  ...  done successfully.



Executing test function test.relativeBarPlot  ...  done successfully.



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:52:52.347728 INFO::preprocessReads.R/preprocessReads: starting...
2023-05-09 18:52:52.355493 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2023-05-09 18:52:52.368817 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2023-05-09 18:52:52.372078 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:52:56.17496 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:52:56.177055 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-05-09 18:52:59.208754 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2023-05-09 18:52:59.274853 DEBUG::tools.R/processChunks: done
2023-05-09 18:52:59.278002 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2023-05-09 18:52:59.280176 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2023-05-09 18:52:59.282638 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2023-05-09 18:52:59.284683 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2023-05-09 18:52:59.293219 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-05-09 18:52:59.295738 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2023-05-09 18:52:59.298764 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2023-05-09 18:52:59.305326 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2023-05-09 18:52:59.31146 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2023-05-09 18:53:01.428485 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2023-05-09 18:53:03.151282 INFO::preprocessReads.R/preprocessReads: done
2023-05-09 18:53:03.236583 INFO::alignReads.R/alignReads: starting alignment...
2023-05-09 18:53:03.242069 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:53:07.198209 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:53:07.200517 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-05-09 18:53:12.866435 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.094 minutes
2023-05-09 18:53:12.870179 DEBUG::tools.R/processChunks: done
2023-05-09 18:53:12.872094 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2023-05-09 18:53:12.912404 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2023-05-09 18:53:12.921197 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2023-05-09 18:53:12.928722 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2023-05-09 18:53:12.931515 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2023-05-09 18:53:13.128357 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2023-05-09 18:53:13.188887 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2023-05-09 18:53:13.190271 INFO::alignReads.R/alignReads: done
2023-05-09 18:53:13.280718 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2023-05-09 18:53:13.304377 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:53:17.254126 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:53:17.256275 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-05-09 18:53:19.895281 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2023-05-09 18:53:19.898525 DEBUG::tools.R/processChunks: done
2023-05-09 18:53:19.900603 INFO::countGenomicFeatures.R/mergeCounts: starting...
2023-05-09 18:53:19.912637 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2023-05-09 18:53:19.922673 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2023-05-09 18:53:19.93 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2023-05-09 18:53:19.935244 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2023-05-09 18:53:19.940452 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2023-05-09 18:53:19.945528 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2023-05-09 18:53:19.953316 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2023-05-09 18:53:19.957472 INFO::countGenomicFeatures.R/mergeCounts: done
2023-05-09 18:53:19.962433 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2023-05-09 18:53:19.964655 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2023-05-09 18:53:20.230237 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2023-05-09 18:53:20.231473 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2023-05-09 18:53:20.318569 INFO::coverage.R/calculateCoverage: starting...
2023-05-09 18:53:20.324507 DEBUG::tools.R/processChunks: starting...
2023-05-09 18:53:24.403889 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2023-05-09 18:53:24.423611 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2023-05-09 18:53:26.810199 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2023-05-09 18:53:26.81378 DEBUG::tools.R/processChunks: done
2023-05-09 18:53:28.727759 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2023-05-09 18:53:28.732198 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2023-05-09 18:53:28.849742 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2023-05-09 18:53:28.852919 INFO::coverage.R/calculateCoverage: done
2023-05-09 18:53:28.854868 INFO::analyzeVariants/analyzeVariants: starting ...
2023-05-09 18:53:28.943584 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2023-05-09 18:53:41.79124 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2023-05-09 18:53:41.881784 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2023-05-09 18:53:41.902174 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2023-05-09 18:53:41.903791 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2023-05-09 18:53:41.907221 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2023-05-09 18:53:41.908922 INFO::analyzeVariants.R/wrap.callVariants: ...done
2023-05-09 18:53:41.910149 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2023-05-09 18:53:42.182194 INFO::analyzeVariants.R/writeVCF: ...done
2023-05-09 18:53:42.30044 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2023-05-09 18:53:42.302945 INFO::analyzeVariants/analyzeVariants: done
2023-05-09 18:53:42.309293 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpft32Hq/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/config/default-config.txt 
2023-05-09 18:53:42.678056 INFO::io.R/saveWithID: saving file= /tmp/Rtmpft32Hq/test.calcTargetLengths.4071f77c92a01/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 May  9 18:53:59 2023 
*********************************************** 
Number of test functions: 61 
Number of deactivated test functions: 10 
Number of errors: 0 
Number of failures: 0 

 
1 Test Suite : 
HTSeqGenie unit testing - 61 test functions, 0 errors, 0 failures



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (33.05 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (20.56 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.66 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (78.31 seconds)
test.wrap.callVariants: (4 checks) ... OK (11.36 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (21.91 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.86 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.18 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.65 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (38.11 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (31.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.88 seconds)
test.isSparse: (5 checks) ... OK (0.12 seconds)
test.mergeCoverage: (1 checks) ... OK (1.77 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.37 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.2 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.43 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.5 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.05 seconds)
test.isAdapter: (5 checks) ... OK (0.16 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.1 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.38 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.53 seconds)
test.getRRNAIds: (1 checks) ... OK (0.32 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.25 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.08 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.06 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.gatk.R 
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.21 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.23 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.42 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.23 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.21 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.72 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.17 seconds)
test.getObjectFilename: (4 checks) ... OK (0.01 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.25 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (66.67 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.picard.R 
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (10.68 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.98 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.29 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.11 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.14 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.16 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.06 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (50.32 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.37 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (16.37 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R-devel_2023-03-12_r83975-bin/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.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 
312.814  85.777 440.585

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

nameusersystemelapsed
HTSeqGenie0.0000.0000.001
buildGenomicFeaturesFromTxDb000
runPipeline000