Multiple platform build/check report for BioC 3.20 - CHECK results for HTSeqGenie on nebbiolo2

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo2	Linux (Ubuntu 22.04.3 LTS)	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4643
palomino6	Windows Server 2022 Datacenter	x64	4.4.1 (2024-06-14 ucrt) -- "Race for Your Life"	4414
lconway	macOS 12.7.1 Monterey	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4442
kjohnson3	macOS 13.6.5 Ventura	arm64	4.4.1 (2024-06-14) -- "Race for Your Life"	4391
kunpeng2	Linux (openEuler 22.03 LTS-SP1)	aarch64	4.4.1 (2024-06-14) -- "Race for Your Life"	3833
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 nebbiolo2

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.
- If 'R CMD check' started to fail recently on the Linux builder(s) over a missing dependency, add the missing dependency to 'Suggests:' in your DESCRIPTION file. See Renviron.bioc for more information.

raw results

Summary

Package: HTSeqGenie

Version: 4.35.0

Command: /home/biocbuild/bbs-3.20-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.20-bioc/R/site-library --timings HTSeqGenie_4.35.0.tar.gz

StartedAt: 2024-07-05 23:43:24 -0400 (Fri, 05 Jul 2024)

EndedAt: 2024-07-05 23:57:06 -0400 (Fri, 05 Jul 2024)

EllapsedTime: 822.6 seconds

RetCode: 0

Status: OK

CheckDir: HTSeqGenie.Rcheck

Warnings: 0

Command output

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


* using log directory ‘/home/biocbuild/bbs-3.20-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.4.1 (2024-06-14)
* using platform: x86_64-pc-linux-gnu
* R was compiled by
    gcc (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0
    GNU Fortran (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0
* running under: Ubuntu 22.04.4 LTS
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.35.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 code files for non-ASCII characters ... OK
* checking R files for syntax errors ... OK
* checking whether the package can be loaded ... OK
* checking whether the package can be loaded with stated dependencies ... OK
* checking whether the package can be unloaded cleanly ... OK
* checking whether the namespace can be loaded with stated dependencies ... OK
* checking whether the namespace can be unloaded cleanly ... OK
* checking loading without being on the library search path ... OK
* checking whether 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 ... NOTE
checkRd: (-1) calculateTargetLengths.Rd:17: Lost braces; missing escapes or markup?
    17 | Target length table and writes two files in {save_dir}/reports/images/TargetLenghts.[pdf|png]"
       |                                             ^
checkRd: (-1) initLog.Rd:18: Lost braces; missing escapes or markup?
    18 | Setup logging file in {save_dir}/progress.log
       |                       ^
* 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 ... NOTE
Documented arguments not in \usage in Rd file 'findVariantFile.Rd':
  ‘dir_path’

Documented arguments not in \usage in Rd file 'logdebug.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'logerror.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'loginfo.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'logwarn.Rd':
  ‘...’

Functions with \usage entries need to have the appropriate \alias
entries, and all their arguments documented.
The \usage entries must correspond to syntactically valid R code.
See chapter ‘Writing R documentation files’ in the ‘Writing R
Extensions’ manual.
* 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 ... OK
* checking re-building of vignette outputs ... OK
* checking PDF version of manual ... OK
* DONE

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

Installation output

HTSeqGenie.Rcheck/00install.out

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


* installing to library ‘/home/biocbuild/bbs-3.20-bioc/R/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 version 4.4.1 (2024-06-14) -- "Race for Your Life"
Copyright (C) 2024 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu

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, table, tapply,
    union, unique, unsplit, which.max, which.min

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

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

    findMatches

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

    I, expand.grid, unname

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

Attaching package: 'Biostrings'

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

    strsplit

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

Attaching package: 'MatrixGenerics'

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

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

Loading required package: Biobase
Welcome to Bioconductor

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


Attaching package: 'Biobase'

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

    rowMedians

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

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

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

    tabulate

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


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:49:02.495774 INFO::preprocessReads.R/preprocessReads: starting...
2024-07-05 23:49:02.504953 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:49:02.50852 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-07-05 23:49:02.510701 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:49:05.249423 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:49:05.250833 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/chunks/chunk_000001/logs/progress.log
2024-07-05 23:49:07.974693 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-07-05 23:49:07.976144 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/chunks/chunk_000002/logs/progress.log
2024-07-05 23:49:10.697214 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-07-05 23:49:10.69855 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/chunks/chunk_000003/logs/progress.log
2024-07-05 23:49:13.433894 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-07-05 23:49:13.467144 DEBUG::tools.R/processChunks: done
2024-07-05 23:49:13.470963 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:49:13.473201 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/results/test_pe.adapter_contaminated_1.RData
2024-07-05 23:49:13.475892 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-07-05 23:49:13.477362 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/results/test_pe.adapter_contaminated_2.RData
2024-07-05 23:49:13.486311 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
2024-07-05 23:49:13.488513 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/results/test_pe.summary_preprocess.tab
2024-07-05 23:49:13.49184 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/bams/processed.aligner_input_1.fastq ...
2024-07-05 23:49:13.496815 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/bams/processed.aligner_input_2.fastq ...
2024-07-05 23:49:13.499892 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/reports/shortReadReport_1 ...
2024-07-05 23:49:14.820106 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/reports/shortReadReport_2 ...
2024-07-05 23:49:15.850438 INFO::preprocessReads.R/preprocessReads: done
2024-07-05 23:49:15.917646 INFO::alignReads.R/alignReads: starting alignment...
2024-07-05 23:49:15.923832 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:49:19.688679 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:49:19.690893 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/chunks/chunk_000001/logs/progress.log
2024-07-05 23:49:22.547717 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2024-07-05 23:49:22.550527 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/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.
2024-07-05 23:49:25.173175 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-07-05 23:49:25.176067 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/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.
2024-07-05 23:49:27.782566 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-07-05 23:49:27.786359 DEBUG::tools.R/processChunks: done
2024-07-05 23:49:27.788387 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.
2024-07-05 23:49:28.031183 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-07-05 23:49:28.04155 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/results/test_pe.summary_alignment.tab
2024-07-05 23:49:28.049233 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/results/test_pe.summary_analyzed_bamstats.tab
2024-07-05 23:49:28.051025 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-07-05 23:49:28.305957 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.13cf0e701b79b7/results/test_pe.summary_target_lengths.tab
2024-07-05 23:49:28.354144 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-07-05 23:49:28.355129 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:49:28.586257 INFO::preprocessReads.R/preprocessReads: starting...
2024-07-05 23:49:28.590192 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:49:28.665631 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-07-05 23:49:28.670852 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:49:28.673957 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-07-05 23:49:28.676071 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:49:31.656692 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:49:31.658233 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/chunks/chunk_000001/logs/progress.log
2024-07-05 23:49:34.433759 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-07-05 23:49:34.435326 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/chunks/chunk_000002/logs/progress.log
2024-07-05 23:49:37.113963 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-07-05 23:49:37.115553 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/chunks/chunk_000003/logs/progress.log
2024-07-05 23:49:39.856664 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-07-05 23:49:39.858055 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/chunks/chunk_000004/logs/progress.log
2024-07-05 23:49:42.544615 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2024-07-05 23:49:42.591929 DEBUG::tools.R/processChunks: done
2024-07-05 23:49:42.597172 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:49:42.600849 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/results/test_pe.adapter_contaminated_1.RData
2024-07-05 23:49:42.605375 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-07-05 23:49:42.608119 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/results/test_pe.adapter_contaminated_2.RData
2024-07-05 23:49:42.622925 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
2024-07-05 23:49:42.625981 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/results/test_pe.summary_preprocess.tab
2024-07-05 23:49:42.630966 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/bams/processed.aligner_input_1.fastq ...
2024-07-05 23:49:42.637996 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/bams/processed.aligner_input_2.fastq ...
2024-07-05 23:49:42.64223 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/reports/shortReadReport_1 ...
2024-07-05 23:49:43.911549 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.alignReads.sparsechunks.13cf0e4cc7aa9/reports/shortReadReport_2 ...
2024-07-05 23:49:44.883125 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:49:45.036261 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-07-05 23:49:45.040836 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/Rtmp5fn0zu/test.alignReadsOneSingleEnd.13cf0e26292cbb/bams/test.alignReads /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-07-05 23:49:45.212355 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-07-05 23:49:45.311148 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReadsOneSingleEnd.13cf0e26292cbb/results/test.alignReads.summary_alignment.tab
2024-07-05 23:49:45.353643 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.alignReadsOneSingleEnd.13cf0e26292cbb/results/test.alignReads.summary_analyzed_bamstats.tab
2024-07-05 23:49:45.355203 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:49:45.651725 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.genotype.13cf0e48c6c3ab/results/test_pe.coverage.RData
2024-07-05 23:49:45.653615 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5fn0zu/test.genotype.13cf0e48c6c3ab/results/test_pe.coverage.bw
2024-07-05 23:49:45.771113 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.genotype.13cf0e48c6c3ab/results/test_pe.summary_coverage.tab
2024-07-05 23:49:45.772888 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:49:56.340374 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:49:56.427786 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:49:56.44587 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:49:56.447476 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.genotype.13cf0e48c6c3ab/results/test_pe.raw_variants.RData
2024-07-05 23:49:56.449944 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.genotype.13cf0e48c6c3ab/results/test_pe.filtered_variants.RData
2024-07-05 23:49:56.45132 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-07-05 23:49:56.452507 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-07-05 23:49:56.846847 INFO::analyzeVariants.R/writeVCF: ...done
2024-07-05 23:49:56.848044 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-07-05 23:50:50.859566 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-07-05 23:50:51.253718 INFO::analyzeVariants.R/writeVCF: ...done
2024-07-05 23:50:51.254625 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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:50:51.648411 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:51:01.700061 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:51:01.775398 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:51:01.793308 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:51:01.794851 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.13cf0e42cda/results/test_pe.raw_variants.RData
2024-07-05 23:51:01.797385 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.13cf0e42cda/results/test_pe.filtered_variants.RData
2024-07-05 23:51:01.798818 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:51:01.945803 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:51:11.740817 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:51:11.800172 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:51:11.817237 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:51:11.81863 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.filters.13cf0e1b04af46/results/test_pe.raw_variants.RData
2024-07-05 23:51:11.821068 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.filters.13cf0e1b04af46/results/test_pe.filtered_variants.RData
2024-07-05 23:51:11.822338 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-07-05 23:51:11.823914 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:51:21.745698 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:51:21.784467 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:51:21.802201 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:51:21.80365 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.filters.13cf0e1b04af46/results/test_pe.raw_variants.RData
2024-07-05 23:51:21.806373 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.filters.13cf0e1b04af46/results/test_pe.filtered_variants.RData
2024-07-05 23:51:21.808438 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:51:22.145044 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:51:22.146748 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-07-05 23:51:25.167787 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:51:25.245347 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:51:25.263446 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:51:25.264994 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.which.13cf0e36a0add/results/test_pe.raw_variants.RData
2024-07-05 23:51:25.266837 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.wrap.callVariants.which.13cf0e36a0add/results/test_pe.filtered_variants.RData
2024-07-05 23:51:25.268297 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:51:25.45309 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-07-05 23:51:25.454317 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:51:27.229447 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-07-05 23:51:27.422233 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  ... 2024-07-05 23:52:20.587269 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/gqcuafnt/merged/results/bla.coverage.RData
2024-07-05 23:52:20.590041 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5fn0zu/gqcuafnt/merged/results/bla.coverage.bw
2024-07-05 23:52:20.663303 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/gqcuafnt/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-07-05 23:52:21.630657 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/mcopbsyv/merged/results/bla.coverage.RData
2024-07-05 23:52:21.632037 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5fn0zu/mcopbsyv/merged/results/bla.coverage.bw
2024-07-05 23:52:21.642633 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/mcopbsyv/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:22.79012 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-07-05 23:52:22.791153 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp5fn0zu/test.detectRRNA.13cf0e7829437b/bams/rRNA_contam/input1.fastq
2024-07-05 23:52:22.794185 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/Rtmp5fn0zu/test.detectRRNA.13cf0e7829437b/bams/rRNA_contam/test_se /tmp/Rtmp5fn0zu/test.detectRRNA.13cf0e7829437b/bams/rRNA_contam/input1.fastq 2>&1
2024-07-05 23:52:22.918786 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-07-05 23:52:22.919719 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:23.027407 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-07-05 23:52:23.028323 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp5fn0zu/test.detectRRNA.paired_end.13cf0e7842e821/bams/rRNA_contam/input1.fastq
2024-07-05 23:52:23.029671 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp5fn0zu/test.detectRRNA.paired_end.13cf0e7842e821/bams/rRNA_contam/input2.fastq
2024-07-05 23:52:23.031683 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/Rtmp5fn0zu/test.detectRRNA.paired_end.13cf0e7842e821/bams/rRNA_contam/test_pe /tmp/Rtmp5fn0zu/test.detectRRNA.paired_end.13cf0e7842e821/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp5fn0zu/test.detectRRNA.paired_end.13cf0e7842e821/bams/rRNA_contam/input2.fastq 2>&1
2024-07-05 23:52:23.243193 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-07-05 23:52:23.244106 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-07-05 23:52:23.261559 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/Rtmp5fn0zu/test_get_rRNA_idsbawfphlz/test_pe /tmp/Rtmp5fn0zu/test_get_rRNA_idsbawfphlz/1.fastq -a paired /tmp/Rtmp5fn0zu/test_get_rRNA_idsbawfphlz/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-07-05 23:52:23.517369 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/Rtmp5fn0zu/test_get_rRNAIds_randomgpdwjmns/test_pe /tmp/Rtmp5fn0zu/test_get_rRNAIds_randomgpdwjmns/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-07-05 23:52:23.711576 INFO::filterQuality.R/filterQuality: filterByLength...
2024-07-05 23:52:23.713089 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-07-05 23:52:23.713943 INFO::filterQuality.R/filterByLength: done
2024-07-05 23:52:23.758617 INFO::filterQuality.R/filterQuality: filterByLength...
2024-07-05 23:52:23.759504 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-07-05 23:52:23.76026 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-07-05 23:52:23.806075 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-07-05 23:52:23.814574 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-07-05 23:52:23.815609 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-07-05 23:52:23.81961 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-07-05 23:52:23.820484 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-07-05 23:52:23.824439 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-07-05 23:52:23.825296 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-07-05 23:52:23.82925 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



Executing test function test.callVariantsGATK  ... Timing stopped at: 0 0 0.001
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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:24.07699 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:24.079132 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:24.249716 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:24.31421 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-07-05 23:52:24.316922 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:24.31918 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:24.505931 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:24.643189 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:24.766788 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:24.808121 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-07-05 23:52:24.810427 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:24.812477 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:24.982261 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:25.022144 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-07-05 23:52:25.024412 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:25.026417 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/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/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:52:25.615063 INFO::preprocessReads.R/preprocessReads: starting...
2024-07-05 23:52:25.621382 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:52:25.624768 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-07-05 23:52:25.627177 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:52:29.006301 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:52:29.007737 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000001/logs/progress.log
2024-07-05 23:52:31.585823 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-07-05 23:52:31.587342 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000002/logs/progress.log
2024-07-05 23:52:34.177571 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-07-05 23:52:34.178942 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000003/logs/progress.log
2024-07-05 23:52:36.853221 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-07-05 23:52:38.208817 DEBUG::tools.R/processChunks: done
2024-07-05 23:52:38.211381 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:52:38.212899 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.adapter_contaminated_1.RData
2024-07-05 23:52:38.214719 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-07-05 23:52:38.216041 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.adapter_contaminated_2.RData
2024-07-05 23:52:38.223276 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
2024-07-05 23:52:38.224692 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.summary_preprocess.tab
2024-07-05 23:52:38.226709 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/bams/processed.aligner_input_1.fastq ...
2024-07-05 23:52:38.230648 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/bams/processed.aligner_input_2.fastq ...
2024-07-05 23:52:38.233584 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/reports/shortReadReport_1 ...
2024-07-05 23:52:39.409121 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/reports/shortReadReport_2 ...
2024-07-05 23:52:40.420436 INFO::preprocessReads.R/preprocessReads: done
2024-07-05 23:52:40.497919 INFO::alignReads.R/alignReads: starting alignment...
2024-07-05 23:52:40.502446 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:52:43.336266 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:52:43.337869 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000001/logs/progress.log
2024-07-05 23:52:45.888803 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-07-05 23:52:45.89082 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/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.
2024-07-05 23:52:48.446618 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-07-05 23:52:48.448308 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/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.
2024-07-05 23:52:50.997404 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2024-07-05 23:52:50.999813 DEBUG::tools.R/processChunks: done
2024-07-05 23:52:51.001308 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.
2024-07-05 23:52:51.179313 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-07-05 23:52:51.186725 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.summary_alignment.tab
2024-07-05 23:52:51.193006 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.summary_analyzed_bamstats.tab
2024-07-05 23:52:51.194696 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-07-05 23:52:51.428974 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.summary_target_lengths.tab
2024-07-05 23:52:51.476489 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-07-05 23:52:51.477579 INFO::alignReads.R/alignReads: done
2024-07-05 23:52:51.556651 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-07-05 23:52:51.577605 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:52:55.768651 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:52:55.770693 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000001/logs/progress.log
2024-07-05 23:52:58.150568 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-07-05 23:52:58.151969 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000002/logs/progress.log
2024-07-05 23:53:00.579244 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2024-07-05 23:53:00.580897 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000003/logs/progress.log
2024-07-05 23:53:03.011679 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2024-07-05 23:53:03.014407 DEBUG::tools.R/processChunks: done
2024-07-05 23:53:03.016379 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-07-05 23:53:03.030651 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.counts_exon.tab
2024-07-05 23:53:03.042468 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.counts_exon_disjoint.tab
2024-07-05 23:53:03.049973 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.counts_gene.tab
2024-07-05 23:53:03.055253 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.counts_gene_coding.tab
2024-07-05 23:53:03.060389 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.counts_gene_exonic.tab
2024-07-05 23:53:03.065593 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.counts_intergenic.tab
2024-07-05 23:53:03.074572 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.counts_intron.tab
2024-07-05 23:53:03.078149 INFO::countGenomicFeatures.R/mergeCounts: done
2024-07-05 23:53:03.083504 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.summary_counts.tab
2024-07-05 23:53:03.08507 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-07-05 23:53:03.367966 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-07-05 23:53:03.368951 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-07-05 23:53:03.456386 INFO::coverage.R/calculateCoverage: starting...
2024-07-05 23:53:03.460356 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:53:06.452302 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:53:06.454257 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000001/logs/progress.log
2024-07-05 23:53:08.595373 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-07-05 23:53:08.596839 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000002/logs/progress.log
2024-07-05 23:53:10.757735 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-07-05 23:53:10.759403 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/chunks/chunk_000003/logs/progress.log
2024-07-05 23:53:12.952645 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2024-07-05 23:53:12.956551 DEBUG::tools.R/processChunks: done
2024-07-05 23:53:14.63775 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.coverage.RData
2024-07-05 23:53:14.639389 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.coverage.bw
2024-07-05 23:53:14.651322 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.summary_coverage.tab
2024-07-05 23:53:14.65264 INFO::coverage.R/calculateCoverage: done
2024-07-05 23:53:14.655021 INFO::analyzeVariants/analyzeVariants: starting ...
2024-07-05 23:53:14.746027 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:53:18.234537 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:53:18.309469 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:53:18.32595 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:53:18.327369 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.raw_variants.RData
2024-07-05 23:53:18.329037 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.filtered_variants.RData
2024-07-05 23:53:18.330295 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-07-05 23:53:18.331264 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-07-05 23:53:18.568061 INFO::analyzeVariants.R/writeVCF: ...done
2024-07-05 23:53:18.663032 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/results/test_pe.summary_variants.tab
2024-07-05 23:53:18.665094 INFO::analyzeVariants/analyzeVariants: done
2024-07-05 23:53:18.668728 INFO::Pipeline run successful.
2024-07-05 23:53:18.894862 INFO::mergeLanes.R/doMergeLanes: starting...
2024-07-05 23:53:18.901783 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:53:18.90516 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.adapter_contaminated_1.RData
2024-07-05 23:53:18.90968 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-07-05 23:53:18.912711 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.adapter_contaminated_2.RData
2024-07-05 23:53:18.930445 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
2024-07-05 23:53:18.934518 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.summary_preprocess.tab
2024-07-05 23:53:18.938146 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.
2024-07-05 23:53:19.218005 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-07-05 23:53:19.226023 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.summary_alignment.tab
2024-07-05 23:53:19.234519 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.summary_analyzed_bamstats.tab
2024-07-05 23:53:19.236769 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-07-05 23:53:19.496959 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.summary_target_lengths.tab
2024-07-05 23:53:19.551145 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-07-05 23:53:19.593975 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-07-05 23:53:19.617558 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.counts_exon.tab
2024-07-05 23:53:19.631705 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.counts_exon_disjoint.tab
2024-07-05 23:53:19.641206 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.counts_gene.tab
2024-07-05 23:53:19.648408 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.counts_gene_coding.tab
2024-07-05 23:53:19.655435 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.counts_gene_exonic.tab
2024-07-05 23:53:19.662839 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.counts_intergenic.tab
2024-07-05 23:53:19.676795 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.counts_intron.tab
2024-07-05 23:53:19.680273 INFO::countGenomicFeatures.R/mergeCounts: done
2024-07-05 23:53:19.687174 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.summary_counts.tab
2024-07-05 23:53:19.689029 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-07-05 23:53:19.907005 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-07-05 23:53:21.893848 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.coverage.RData
2024-07-05 23:53:21.896061 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.coverage.bw
2024-07-05 23:53:21.907235 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.summary_coverage.tab
2024-07-05 23:53:21.945662 INFO::analyzeVariants/analyzeVariants: starting ...
2024-07-05 23:53:22.025162 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:53:25.217602 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:53:25.28853 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:53:25.304802 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:53:25.306112 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.raw_variants.RData
2024-07-05 23:53:25.307749 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.filtered_variants.RData
2024-07-05 23:53:25.309027 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-07-05 23:53:25.310006 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-07-05 23:53:25.51228 INFO::analyzeVariants.R/writeVCF: ...done
2024-07-05 23:53:25.604706 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.mergeLanes.13cf0e7ad1a688/merged/results/merged.summary_variants.tab
2024-07-05 23:53:25.606738 INFO::analyzeVariants/analyzeVariants: done
2024-07-05 23:53:25.609927 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:53:25.829706 INFO::preprocessReads.R/preprocessReads: starting...
2024-07-05 23:53:25.835956 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:53:25.839299 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-07-05 23:53:25.841613 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:53:30.106844 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:53:30.108287 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/chunks/chunk_000001/logs/progress.log
2024-07-05 23:53:32.727827 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-07-05 23:53:32.768527 DEBUG::tools.R/processChunks: done
2024-07-05 23:53:32.770651 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:53:32.771984 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/results/test_pe.adapter_contaminated_1.RData
2024-07-05 23:53:32.773418 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-07-05 23:53:32.774563 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/results/test_pe.adapter_contaminated_2.RData
2024-07-05 23:53:32.780121 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
2024-07-05 23:53:32.78162 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/results/test_pe.summary_preprocess.tab
2024-07-05 23:53:32.783357 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/bams/processed.aligner_input_1.fastq ...
2024-07-05 23:53:32.786439 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/bams/processed.aligner_input_2.fastq ...
2024-07-05 23:53:32.789675 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/reports/shortReadReport_1 ...
2024-07-05 23:53:34.082332 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.preprocessReads.13cf0e158fd158/reports/shortReadReport_2 ...
2024-07-05 23:53:35.108949 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:53:37.626598 INFO::preprocessReads.R/preprocessReads: starting...
2024-07-05 23:53:37.633375 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:53:37.637215 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-07-05 23:53:37.639633 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:53:40.722851 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:53:40.724338 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/chunks/chunk_000001/logs/progress.log
2024-07-05 23:53:43.33569 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-07-05 23:53:43.33748 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/chunks/chunk_000002/logs/progress.log
2024-07-05 23:53:45.928541 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-07-05 23:53:45.929817 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/chunks/chunk_000003/logs/progress.log
2024-07-05 23:53:48.576361 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-07-05 23:53:48.626773 DEBUG::tools.R/processChunks: done
2024-07-05 23:53:48.629733 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:53:48.631385 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/results/test_pe.adapter_contaminated_1.RData
2024-07-05 23:53:48.633454 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-07-05 23:53:48.634918 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/results/test_pe.adapter_contaminated_2.RData
2024-07-05 23:53:48.643209 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
2024-07-05 23:53:48.644979 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/results/test_pe.summary_preprocess.tab
2024-07-05 23:53:48.64747 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/bams/processed.aligner_input_1.fastq ...
2024-07-05 23:53:48.651306 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/bams/processed.aligner_input_2.fastq ...
2024-07-05 23:53:48.654416 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/reports/shortReadReport_1 ...
2024-07-05 23:53:49.989928 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.preprocessReads.minichunks.13cf0e4df930b0/reports/shortReadReport_2 ...
2024-07-05 23:53:51.008555 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:53:51.244056 INFO::preprocessReads.R/preprocessReads: starting...
2024-07-05 23:53:51.250165 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-07-05 23:53:51.252652 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:53:54.352528 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:53:54.353927 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5fn0zu/test.preprocessReads_single_end.13cf0e5d3517f7/chunks/chunk_000001/logs/progress.log
2024-07-05 23:53:56.683416 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-07-05 23:53:56.718969 DEBUG::tools.R/processChunks: done
2024-07-05 23:53:56.721455 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:53:56.722939 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads_single_end.13cf0e5d3517f7/results/test_se.adapter_contaminated_1.RData
2024-07-05 23:53:56.728806 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
2024-07-05 23:53:56.730323 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.preprocessReads_single_end.13cf0e5d3517f7/results/test_se.summary_preprocess.tab
2024-07-05 23:53:56.732022 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5fn0zu/test.preprocessReads_single_end.13cf0e5d3517f7/bams/processed.aligner_input_1.fastq ...
2024-07-05 23:53:56.736084 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5fn0zu/test.preprocessReads_single_end.13cf0e5d3517f7/reports/shortReadReport_1 ...
2024-07-05 23:53:57.998781 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.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:53:58.642298 INFO::preprocessReads.R/preprocessReads: starting...
2024-07-05 23:53:58.648562 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-07-05 23:53:58.652537 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-07-05 23:53:58.654914 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:54:02.756589 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:54:02.75804 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-07-05 23:54:05.544862 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-07-05 23:54:05.580648 DEBUG::tools.R/processChunks: done
2024-07-05 23:54:05.582676 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-07-05 23:54:05.583957 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-07-05 23:54:05.585342 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-07-05 23:54:05.586452 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-07-05 23:54:05.591926 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
2024-07-05 23:54:05.593422 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-07-05 23:54:05.595158 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-07-05 23:54:05.599575 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-07-05 23:54:05.603333 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-07-05 23:54:06.961472 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-07-05 23:54:08.133726 INFO::preprocessReads.R/preprocessReads: done
2024-07-05 23:54:08.226195 INFO::alignReads.R/alignReads: starting alignment...
2024-07-05 23:54:08.23093 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:54:11.930485 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:54:11.932761 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.
2024-07-05 23:54:19.692348 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.129 minutes
2024-07-05 23:54:19.697028 DEBUG::tools.R/processChunks: done
2024-07-05 23:54:19.699669 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-07-05 23:54:19.820048 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-07-05 23:54:19.832129 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-07-05 23:54:19.859821 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-07-05 23:54:19.864376 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-07-05 23:54:20.315254 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-07-05 23:54:20.429232 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-07-05 23:54:20.431373 INFO::alignReads.R/alignReads: done
2024-07-05 23:54:20.772285 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-07-05 23:54:20.835081 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:54:28.802397 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:54:28.806735 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-07-05 23:54:31.867329 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2024-07-05 23:54:31.871208 DEBUG::tools.R/processChunks: done
2024-07-05 23:54:31.87389 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-07-05 23:54:31.890651 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-07-05 23:54:31.908582 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-07-05 23:54:31.921093 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-07-05 23:54:31.92869 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-07-05 23:54:31.936658 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-07-05 23:54:31.944163 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-07-05 23:54:31.956443 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-07-05 23:54:31.965962 INFO::countGenomicFeatures.R/mergeCounts: done
2024-07-05 23:54:31.973946 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-07-05 23:54:31.977474 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-07-05 23:54:32.356442 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-07-05 23:54:32.358179 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-07-05 23:54:32.615469 INFO::coverage.R/calculateCoverage: starting...
2024-07-05 23:54:32.623181 DEBUG::tools.R/processChunks: starting...
2024-07-05 23:54:36.305279 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-07-05 23:54:36.307574 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-07-05 23:54:38.897137 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-07-05 23:54:38.901677 DEBUG::tools.R/processChunks: done
2024-07-05 23:54:41.766109 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-07-05 23:54:41.769303 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-07-05 23:54:41.920886 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-07-05 23:54:41.923899 INFO::coverage.R/calculateCoverage: done
2024-07-05 23:54:41.92678 INFO::analyzeVariants/analyzeVariants: starting ...
2024-07-05 23:54:42.130882 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-07-05 23:54:57.942633 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-07-05 23:54:58.108765 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-07-05 23:54:58.137586 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-07-05 23:54:58.139956 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-07-05 23:54:58.144447 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-07-05 23:54:58.147046 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-07-05 23:54:58.148759 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-07-05 23:54:58.584632 INFO::analyzeVariants.R/writeVCF: ...done
2024-07-05 23:54:58.81708 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-07-05 23:54:58.820695 INFO::analyzeVariants/analyzeVariants: done
2024-07-05 23:54:58.827657 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5fn0zu/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-07-05 23:54:59.087923 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5fn0zu/test.calcTargetLengths.13cf0e33361496/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 -- Fri Jul  5 23:55:15 2024 
*********************************************** 
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.20-bioc/R/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (27.16 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (16.52 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.47 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (66.17 seconds)
test.wrap.callVariants: (4 checks) ... OK (10.27 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (20.01 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (3.46 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.19 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (2.06 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (27.38 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (23.56 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.72 seconds)
test.isSparse: (5 checks) ... OK (0.09 seconds)
test.mergeCoverage: (1 checks) ... OK (1.41 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.13 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.28 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.34 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.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.03 seconds)
test.isAdapter: (5 checks) ... OK (0.11 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.07 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.27 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.32 seconds)
test.getRRNAIds: (1 checks) ... OK (0.26 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.21 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.05 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.04 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/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.14 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.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.15 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.25 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.14 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.13 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.43 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.1 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.16 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (60.29 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/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.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (9.47 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.9 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (6.99 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.12 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.09 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.13 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.06 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (60.43 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.26 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (15.81 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.05 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.15 seconds) 

runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
> 
> proc.time()
   user  system elapsed 
249.194  87.935 390.093

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

name	user	system	elapsed
HTSeqGenie	0	0	0
buildGenomicFeaturesFromTxDb	0.001	0.000	0.000
runPipeline	0	0	0