Multiple platform build/check report for BioC 3.21 - CHECK results for HTSeqGenie on nebbiolo1

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo1	Linux (Ubuntu 24.04.3 LTS)	x86_64	4.5.1 (2025-06-13) -- "Great Square Root"	4827
merida1	macOS 12.7.5 Monterey	x86_64	4.5.1 RC (2025-06-05 r88288) -- "Great Square Root"	4608
kjohnson1	macOS 13.6.6 Ventura	arm64	4.5.1 Patched (2025-06-14 r88325) -- "Great Square Root"	4549
kunpeng2	Linux (openEuler 24.03 LTS)	aarch64	R Under development (unstable) (2025-02-19 r87757) -- "Unsuffered Consequences"	4580
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 nebbiolo1

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.38.0

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

StartedAt: 2025-09-29 00:13:23 -0400 (Mon, 29 Sep 2025)

EndedAt: 2025-09-29 00:53:24 -0400 (Mon, 29 Sep 2025)

EllapsedTime: 2400.8 seconds

RetCode: None

Status: TIMEOUT

CheckDir: HTSeqGenie.Rcheck

Warnings: NA

Command output

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


* using log directory ‘/home/biocbuild/bbs-3.21-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.5.1 (2025-06-13)
* using platform: x86_64-pc-linux-gnu
* R was compiled by
    gcc (Ubuntu 13.3.0-6ubuntu2~24.04) 13.3.0
    GNU Fortran (Ubuntu 13.3.0-6ubuntu2~24.04) 13.3.0
* running under: Ubuntu 24.04.3 LTS
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.38.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’

Installation output

HTSeqGenie.Rcheck/00install.out

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


* installing to library ‘/home/biocbuild/bbs-3.21-bioc/R/site-library’
* installing *source* package ‘HTSeqGenie’ ...
** this is package ‘HTSeqGenie’ version ‘4.38.0’
** 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
Warning in fun(libname, pkgname) :
  Package 'HTSeqGenie' is deprecated and will be removed from
  Bioconductor version 3.22
** testing if installed package can be loaded from final location
Warning in fun(libname, pkgname) :
  Package 'HTSeqGenie' is deprecated and will be removed from
  Bioconductor version 3.22
** testing if installed package keeps a record of temporary installation path
* DONE (HTSeqGenie)

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.5.1 (2025-06-13) -- "Great Square Root"
Copyright (C) 2025 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
Loading required package: generics

Attaching package: 'generics'

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

    as.difftime, as.factor, as.ordered, intersect, is.element, setdiff,
    setequal, union


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, is.unsorted, lapply,
    mapply, match, mget, order, paste, pmax, pmax.int, pmin, pmin.int,
    rank, rbind, rownames, sapply, saveRDS, table, tapply, 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

Warning message:
In fun(libname, pkgname) :
  Package 'HTSeqGenie' is deprecated and will be removed from
  Bioconductor version 3.22
> 
> 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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:19:01.486921 INFO::preprocessReads.R/preprocessReads: starting...
2025-09-29 00:19:01.495811 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:19:01.499609 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-09-29 00:19:01.501821 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:19:04.377193 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:19:04.378735 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/chunks/chunk_000001/logs/progress.log
2025-09-29 00:19:07.099304 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-09-29 00:19:07.100574 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/chunks/chunk_000002/logs/progress.log
2025-09-29 00:19:09.803195 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-09-29 00:19:09.804677 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/chunks/chunk_000003/logs/progress.log
2025-09-29 00:19:12.578555 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-09-29 00:19:12.610559 DEBUG::tools.R/processChunks: done
2025-09-29 00:19:12.614596 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:19:12.616881 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/results/test_pe.adapter_contaminated_1.RData
2025-09-29 00:19:12.61961 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-09-29 00:19:12.621252 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/results/test_pe.adapter_contaminated_2.RData
2025-09-29 00:19:12.630461 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
2025-09-29 00:19:12.632703 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/results/test_pe.summary_preprocess.tab
2025-09-29 00:19:12.635929 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/bams/processed.aligner_input_1.fastq ...
2025-09-29 00:19:12.63961 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/bams/processed.aligner_input_2.fastq ...
2025-09-29 00:19:12.642702 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/reports/shortReadReport_1 ...
2025-09-29 00:19:14.04961 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/reports/shortReadReport_2 ...
2025-09-29 00:19:17.65445 INFO::preprocessReads.R/preprocessReads: done
2025-09-29 00:19:17.740755 INFO::alignReads.R/alignReads: starting alignment...
2025-09-29 00:19:17.746937 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:19:20.746202 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:19:20.747997 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/chunks/chunk_000001/logs/progress.log
2025-09-29 00:19:23.58976 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2025-09-29 00:19:23.591504 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/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.
2025-09-29 00:19:26.271744 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-09-29 00:19:26.273338 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/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.
2025-09-29 00:19:28.936861 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-09-29 00:19:28.940665 DEBUG::tools.R/processChunks: done
2025-09-29 00:19:28.942905 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.
2025-09-29 00:19:29.171047 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-09-29 00:19:29.178949 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/results/test_pe.summary_alignment.tab
2025-09-29 00:19:29.185845 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/results/test_pe.summary_analyzed_bamstats.tab
2025-09-29 00:19:29.187411 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-09-29 00:19:29.433209 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.12d3176bea0d09/results/test_pe.summary_target_lengths.tab
2025-09-29 00:19:29.480074 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-09-29 00:19:29.48117 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:19:29.718738 INFO::preprocessReads.R/preprocessReads: starting...
2025-09-29 00:19:29.72197 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:19:29.790218 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-09-29 00:19:29.794774 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:19:29.797895 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-09-29 00:19:29.799917 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:19:32.498753 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:19:32.500289 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/chunks/chunk_000001/logs/progress.log
2025-09-29 00:19:35.224312 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-09-29 00:19:35.226032 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/chunks/chunk_000002/logs/progress.log
2025-09-29 00:19:37.920452 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-09-29 00:19:37.921931 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/chunks/chunk_000003/logs/progress.log
2025-09-29 00:19:40.653502 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-09-29 00:19:40.654816 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/chunks/chunk_000004/logs/progress.log
2025-09-29 00:19:43.336389 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2025-09-29 00:19:43.371658 DEBUG::tools.R/processChunks: done
2025-09-29 00:19:43.375552 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:19:43.37827 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/results/test_pe.adapter_contaminated_1.RData
2025-09-29 00:19:43.381563 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-09-29 00:19:43.383455 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/results/test_pe.adapter_contaminated_2.RData
2025-09-29 00:19:43.394168 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
2025-09-29 00:19:43.396589 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/results/test_pe.summary_preprocess.tab
2025-09-29 00:19:43.400125 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/bams/processed.aligner_input_1.fastq ...
2025-09-29 00:19:43.405584 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/bams/processed.aligner_input_2.fastq ...
2025-09-29 00:19:43.409851 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/reports/shortReadReport_1 ...
2025-09-29 00:19:44.763363 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.alignReads.sparsechunks.12d317281b60ed/reports/shortReadReport_2 ...
2025-09-29 00:19:47.324169 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:19:47.473404 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-09-29 00:19:47.477391 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/RtmpNJLDu9/test.alignReadsOneSingleEnd.12d31716c4af80/bams/test.alignReads /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-09-29 00:19:47.698945 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-09-29 00:19:47.783435 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReadsOneSingleEnd.12d31716c4af80/results/test.alignReads.summary_alignment.tab
2025-09-29 00:19:47.832195 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.alignReadsOneSingleEnd.12d31716c4af80/results/test.alignReads.summary_analyzed_bamstats.tab
2025-09-29 00:19:47.833702 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:19:48.121225 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.genotype.12d3176bf3b0d5/results/test_pe.coverage.RData
2025-09-29 00:19:48.123024 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpNJLDu9/test.genotype.12d3176bf3b0d5/results/test_pe.coverage.bw
2025-09-29 00:19:48.23503 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.genotype.12d3176bf3b0d5/results/test_pe.summary_coverage.tab
2025-09-29 00:19:48.23657 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-09-29 00:19:57.59746 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-09-29 00:19:57.681408 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-09-29 00:19:57.698181 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-09-29 00:19:57.699615 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.genotype.12d3176bf3b0d5/results/test_pe.raw_variants.RData
2025-09-29 00:19:57.702033 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.genotype.12d3176bf3b0d5/results/test_pe.filtered_variants.RData
2025-09-29 00:19:57.703361 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-09-29 00:19:57.704496 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-09-29 00:19:58.094861 INFO::analyzeVariants.R/writeVCF: ...done
2025-09-29 00:19:58.096082 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-09-29 00:21:00.676777 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-09-29 00:21:01.062511 INFO::analyzeVariants.R/writeVCF: ...done
2025-09-29 00:21:01.063575 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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:21:01.479049 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-09-29 00:21:11.201968 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-09-29 00:21:11.290742 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-09-29 00:21:11.309272 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-09-29 00:21:11.310734 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.12d31733d7c0c1/results/test_pe.raw_variants.RData
2025-09-29 00:21:11.313281 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.12d31733d7c0c1/results/test_pe.filtered_variants.RData
2025-09-29 00:21:11.31465 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:21:11.460302 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-09-29 00:21:20.986798 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-09-29 00:21:21.052217 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-09-29 00:21:21.070822 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-09-29 00:21:21.072489 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.filters.12d3173dc51d2/results/test_pe.raw_variants.RData
2025-09-29 00:21:21.075095 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.filters.12d3173dc51d2/results/test_pe.filtered_variants.RData
2025-09-29 00:21:21.076421 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-09-29 00:21:21.078139 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-09-29 00:21:30.713396 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-09-29 00:21:30.756082 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-09-29 00:21:30.773761 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-09-29 00:21:30.775234 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.filters.12d3173dc51d2/results/test_pe.raw_variants.RData
2025-09-29 00:21:30.777932 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.filters.12d3173dc51d2/results/test_pe.filtered_variants.RData
2025-09-29 00:21:30.780043 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:21:31.047256 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-09-29 00:21:31.048742 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-09-29 00:21:33.7881 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-09-29 00:21:33.870167 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-09-29 00:21:33.890365 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-09-29 00:21:33.892029 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.which.12d31778f050e8/results/test_pe.raw_variants.RData
2025-09-29 00:21:33.893851 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.wrap.callVariants.which.12d31778f050e8/results/test_pe.filtered_variants.RData
2025-09-29 00:21:33.895191 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:21:34.043141 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-09-29 00:21:34.044719 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:21:34.228375 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-09-29 00:21:34.447123 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  ... 2025-09-29 00:22:27.058021 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/ehskljto/merged/results/bla.coverage.RData
2025-09-29 00:22:27.060819 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpNJLDu9/ehskljto/merged/results/bla.coverage.bw
2025-09-29 00:22:27.138882 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/ehskljto/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-09-29 00:22:28.211434 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/sznjevwd/merged/results/bla.coverage.RData
2025-09-29 00:22:28.213404 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpNJLDu9/sznjevwd/merged/results/bla.coverage.bw
2025-09-29 00:22:28.22472 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/sznjevwd/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:29.412809 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-09-29 00:22:29.4139 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpNJLDu9/test.detectRRNA.12d31739f25318/bams/rRNA_contam/input1.fastq
2025-09-29 00:22:29.417002 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/RtmpNJLDu9/test.detectRRNA.12d31739f25318/bams/rRNA_contam/test_se /tmp/RtmpNJLDu9/test.detectRRNA.12d31739f25318/bams/rRNA_contam/input1.fastq 2>&1
2025-09-29 00:22:29.586108 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-09-29 00:22:29.587106 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:29.743471 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-09-29 00:22:29.744449 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpNJLDu9/test.detectRRNA.paired_end.12d3171d56ba0b/bams/rRNA_contam/input1.fastq
2025-09-29 00:22:29.745921 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpNJLDu9/test.detectRRNA.paired_end.12d3171d56ba0b/bams/rRNA_contam/input2.fastq
2025-09-29 00:22:29.748044 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/RtmpNJLDu9/test.detectRRNA.paired_end.12d3171d56ba0b/bams/rRNA_contam/test_pe /tmp/RtmpNJLDu9/test.detectRRNA.paired_end.12d3171d56ba0b/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpNJLDu9/test.detectRRNA.paired_end.12d3171d56ba0b/bams/rRNA_contam/input2.fastq 2>&1
2025-09-29 00:22:29.983476 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-09-29 00:22:29.984508 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-09-29 00:22:30.003474 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/RtmpNJLDu9/test_get_rRNA_idsovlcjskg/test_pe /tmp/RtmpNJLDu9/test_get_rRNA_idsovlcjskg/1.fastq -a paired /tmp/RtmpNJLDu9/test_get_rRNA_idsovlcjskg/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-09-29 00:22:30.24685 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/RtmpNJLDu9/test_get_rRNAIds_randomztphmwai/test_pe /tmp/RtmpNJLDu9/test_get_rRNAIds_randomztphmwai/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-09-29 00:22:30.501246 INFO::filterQuality.R/filterQuality: filterByLength...
2025-09-29 00:22:30.502689 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-09-29 00:22:30.503554 INFO::filterQuality.R/filterByLength: done
2025-09-29 00:22:30.549979 INFO::filterQuality.R/filterQuality: filterByLength...
2025-09-29 00:22:30.55091 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-09-29 00:22:30.551715 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-09-29 00:22:30.602048 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-09-29 00:22:30.610911 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-09-29 00:22:30.61203 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-09-29 00:22:30.616467 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-09-29 00:22:30.617508 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-09-29 00:22:30.621931 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-09-29 00:22:30.622915 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-09-29 00:22:30.627256 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.001 0 0
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") : 
  checkGATKJar() test needs gatk.path option set
 done successfully.



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:30.931459 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:30.933739 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:31.111844 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:31.204795 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-09-29 00:22:31.207454 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:31.209582 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:31.400366 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:31.590159 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:31.764685 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:31.815598 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-09-29 00:22:31.818208 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:31.820544 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:32.0078 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:32.05113 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-09-29 00:22:32.053571 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:32.055775 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:22:32.782678 INFO::preprocessReads.R/preprocessReads: starting...
2025-09-29 00:22:32.788381 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:22:32.791704 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-09-29 00:22:32.793914 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:22:35.711637 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:22:35.71303 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000001/logs/progress.log
2025-09-29 00:22:38.269151 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-09-29 00:22:38.27055 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000002/logs/progress.log
2025-09-29 00:22:40.839548 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-09-29 00:22:40.840961 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000003/logs/progress.log
2025-09-29 00:22:43.439549 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-09-29 00:22:43.495143 DEBUG::tools.R/processChunks: done
2025-09-29 00:22:43.498842 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:22:43.501147 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.adapter_contaminated_1.RData
2025-09-29 00:22:43.504029 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-09-29 00:22:43.506173 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.adapter_contaminated_2.RData
2025-09-29 00:22:43.517127 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
2025-09-29 00:22:43.51972 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.summary_preprocess.tab
2025-09-29 00:22:43.523169 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/bams/processed.aligner_input_1.fastq ...
2025-09-29 00:22:43.527733 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/bams/processed.aligner_input_2.fastq ...
2025-09-29 00:22:43.531347 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/reports/shortReadReport_1 ...
2025-09-29 00:22:44.843161 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/reports/shortReadReport_2 ...
2025-09-29 00:22:45.915317 INFO::preprocessReads.R/preprocessReads: done
2025-09-29 00:22:46.022829 INFO::alignReads.R/alignReads: starting alignment...
2025-09-29 00:22:46.027035 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:22:48.896557 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:22:48.898226 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000001/logs/progress.log
2025-09-29 00:22:51.516059 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-09-29 00:22:51.517824 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/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.
2025-09-29 00:22:54.158693 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-09-29 00:22:54.16033 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/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.
2025-09-29 00:22:56.783999 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-09-29 00:22:56.786603 DEBUG::tools.R/processChunks: done
2025-09-29 00:22:56.788179 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.
2025-09-29 00:22:56.988226 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-09-29 00:22:56.996168 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.summary_alignment.tab
2025-09-29 00:22:57.002982 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.summary_analyzed_bamstats.tab
2025-09-29 00:22:57.00484 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-09-29 00:22:57.235285 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.summary_target_lengths.tab
2025-09-29 00:22:57.283458 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-09-29 00:22:57.284644 INFO::alignReads.R/alignReads: done
2025-09-29 00:22:57.395947 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-09-29 00:22:57.416343 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:23:00.37413 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:23:00.375808 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000001/logs/progress.log
2025-09-29 00:23:02.806207 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-09-29 00:23:02.807712 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000002/logs/progress.log
2025-09-29 00:23:05.26324 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2025-09-29 00:23:05.265042 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000003/logs/progress.log
2025-09-29 00:23:07.713874 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2025-09-29 00:23:07.716601 DEBUG::tools.R/processChunks: done
2025-09-29 00:23:07.718405 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-09-29 00:23:07.733736 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.counts_exon.tab
2025-09-29 00:23:07.746246 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.counts_exon_disjoint.tab
2025-09-29 00:23:07.753923 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.counts_gene.tab
2025-09-29 00:23:07.759785 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.counts_gene_coding.tab
2025-09-29 00:23:07.765515 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.counts_gene_exonic.tab
2025-09-29 00:23:07.770898 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.counts_intergenic.tab
2025-09-29 00:23:07.780159 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.counts_intron.tab
2025-09-29 00:23:07.782725 INFO::countGenomicFeatures.R/mergeCounts: done
2025-09-29 00:23:07.788006 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.summary_counts.tab
2025-09-29 00:23:07.789523 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-09-29 00:23:08.154171 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-09-29 00:23:08.155151 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-09-29 00:23:08.258464 INFO::coverage.R/calculateCoverage: starting...
2025-09-29 00:23:08.264988 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:23:11.238185 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:23:11.239932 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000001/logs/progress.log
2025-09-29 00:23:13.42813 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2025-09-29 00:23:13.430049 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000002/logs/progress.log
2025-09-29 00:23:15.609814 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2025-09-29 00:23:15.611641 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/chunks/chunk_000003/logs/progress.log
2025-09-29 00:23:17.831523 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2025-09-29 00:23:17.835042 DEBUG::tools.R/processChunks: done
2025-09-29 00:23:20.142205 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.coverage.RData
2025-09-29 00:23:20.143876 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.coverage.bw
2025-09-29 00:23:20.159317 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.summary_coverage.tab
2025-09-29 00:23:20.16082 INFO::coverage.R/calculateCoverage: done
2025-09-29 00:23:20.162821 INFO::analyzeVariants/analyzeVariants: starting ...
2025-09-29 00:23:20.269783 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-09-29 00:23:23.291116 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-09-29 00:23:23.365227 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-09-29 00:23:23.382113 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-09-29 00:23:23.383523 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.raw_variants.RData
2025-09-29 00:23:23.38524 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.filtered_variants.RData
2025-09-29 00:23:23.386516 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-09-29 00:23:23.387815 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-09-29 00:23:23.607854 INFO::analyzeVariants.R/writeVCF: ...done
2025-09-29 00:23:23.706911 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/results/test_pe.summary_variants.tab
2025-09-29 00:23:23.709147 INFO::analyzeVariants/analyzeVariants: done
2025-09-29 00:23:23.71409 INFO::Pipeline run successful.
2025-09-29 00:23:23.906998 INFO::mergeLanes.R/doMergeLanes: starting...
2025-09-29 00:23:23.911773 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:23:23.914025 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.adapter_contaminated_1.RData
2025-09-29 00:23:23.91697 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-09-29 00:23:23.9189 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.adapter_contaminated_2.RData
2025-09-29 00:23:23.929994 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
2025-09-29 00:23:23.932398 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.summary_preprocess.tab
2025-09-29 00:23:23.934557 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.
2025-09-29 00:23:24.175268 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-09-29 00:23:24.182431 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.summary_alignment.tab
2025-09-29 00:23:24.190628 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.summary_analyzed_bamstats.tab
2025-09-29 00:23:24.192742 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-09-29 00:23:24.439247 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.summary_target_lengths.tab
2025-09-29 00:23:24.491687 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-09-29 00:23:24.535939 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-09-29 00:23:24.559434 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.counts_exon.tab
2025-09-29 00:23:24.57229 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.counts_exon_disjoint.tab
2025-09-29 00:23:24.579815 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.counts_gene.tab
2025-09-29 00:23:24.585874 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.counts_gene_coding.tab
2025-09-29 00:23:24.59186 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.counts_gene_exonic.tab
2025-09-29 00:23:24.59795 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.counts_intergenic.tab
2025-09-29 00:23:24.6107 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.counts_intron.tab
2025-09-29 00:23:24.613528 INFO::countGenomicFeatures.R/mergeCounts: done
2025-09-29 00:23:24.619891 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.summary_counts.tab
2025-09-29 00:23:24.621774 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-09-29 00:23:24.866943 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-09-29 00:23:26.870304 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.coverage.RData
2025-09-29 00:23:26.872726 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.coverage.bw
2025-09-29 00:23:26.883659 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.summary_coverage.tab
2025-09-29 00:23:26.925697 INFO::analyzeVariants/analyzeVariants: starting ...
2025-09-29 00:23:27.012731 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-09-29 00:23:29.907572 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-09-29 00:23:29.980571 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-09-29 00:23:29.997154 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-09-29 00:23:29.998489 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.raw_variants.RData
2025-09-29 00:23:30.000165 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.filtered_variants.RData
2025-09-29 00:23:30.001437 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-09-29 00:23:30.00242 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-09-29 00:23:30.216061 INFO::analyzeVariants.R/writeVCF: ...done
2025-09-29 00:23:30.311225 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.mergeLanes.12d3177fe933b3/merged/results/merged.summary_variants.tab
2025-09-29 00:23:30.313322 INFO::analyzeVariants/analyzeVariants: done
2025-09-29 00:23:30.316776 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0.001 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/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:23:30.612129 INFO::preprocessReads.R/preprocessReads: starting...
2025-09-29 00:23:30.617999 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:23:30.621461 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-09-29 00:23:30.623709 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:23:33.577441 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:23:33.578824 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/chunks/chunk_000001/logs/progress.log
2025-09-29 00:23:36.211349 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-09-29 00:23:36.262094 DEBUG::tools.R/processChunks: done
2025-09-29 00:23:36.264455 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:23:36.26596 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/results/test_pe.adapter_contaminated_1.RData
2025-09-29 00:23:36.267656 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-09-29 00:23:36.268959 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/results/test_pe.adapter_contaminated_2.RData
2025-09-29 00:23:36.275238 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
2025-09-29 00:23:36.27698 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/results/test_pe.summary_preprocess.tab
2025-09-29 00:23:36.278958 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/bams/processed.aligner_input_1.fastq ...
2025-09-29 00:23:36.28274 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/bams/processed.aligner_input_2.fastq ...
2025-09-29 00:23:36.286259 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/reports/shortReadReport_1 ...
2025-09-29 00:23:37.696444 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.preprocessReads.12d317735872c1/reports/shortReadReport_2 ...
2025-09-29 00:23:38.878857 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:23:39.230132 INFO::preprocessReads.R/preprocessReads: starting...
2025-09-29 00:23:39.235957 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:23:39.239387 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-09-29 00:23:39.241684 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:23:42.705079 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:23:42.70685 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/chunks/chunk_000001/logs/progress.log
2025-09-29 00:23:46.623614 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.065 minutes
2025-09-29 00:23:46.630806 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/chunks/chunk_000002/logs/progress.log
2025-09-29 00:23:49.907715 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.055 minutes
2025-09-29 00:23:49.914753 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/chunks/chunk_000003/logs/progress.log
2025-09-29 00:23:53.70295 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.063 minutes
2025-09-29 00:23:53.965455 DEBUG::tools.R/processChunks: done
2025-09-29 00:23:53.970465 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:23:53.977469 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/results/test_pe.adapter_contaminated_1.RData
2025-09-29 00:23:53.984258 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-09-29 00:23:53.991337 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/results/test_pe.adapter_contaminated_2.RData
2025-09-29 00:23:54.022303 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
2025-09-29 00:23:54.033231 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/results/test_pe.summary_preprocess.tab
2025-09-29 00:23:54.041802 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/bams/processed.aligner_input_1.fastq ...
2025-09-29 00:23:54.058731 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/bams/processed.aligner_input_2.fastq ...
2025-09-29 00:23:54.075608 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/reports/shortReadReport_1 ...
2025-09-29 00:23:56.580072 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.preprocessReads.minichunks.12d31772287eb5/reports/shortReadReport_2 ...
2025-09-29 00:23:59.738578 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpNJLDu9/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:24:01.129952 INFO::preprocessReads.R/preprocessReads: starting...
2025-09-29 00:24:01.148712 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-09-29 00:24:01.158116 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:24:10.675356 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:24:10.677538 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpNJLDu9/test.preprocessReads_single_end.12d31719b39d7/chunks/chunk_000001/logs/progress.log
2025-09-29 00:24:13.433231 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-09-29 00:24:13.519309 DEBUG::tools.R/processChunks: done
2025-09-29 00:24:13.523874 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:24:13.526856 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads_single_end.12d31719b39d7/results/test_se.adapter_contaminated_1.RData
2025-09-29 00:24:13.540248 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
2025-09-29 00:24:13.543782 INFO::io.R/saveWithID: saving file= /tmp/RtmpNJLDu9/test.preprocessReads_single_end.12d31719b39d7/results/test_se.summary_preprocess.tab
2025-09-29 00:24:13.547789 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpNJLDu9/test.preprocessReads_single_end.12d31719b39d7/bams/processed.aligner_input_1.fastq ...
2025-09-29 00:24:13.554677 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpNJLDu9/test.preprocessReads_single_end.12d31719b39d7/reports/shortReadReport_1 ...
2025-09-29 00:24:16.387038 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.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-09-29 00:24:17.856937 INFO::preprocessReads.R/preprocessReads: starting...
2025-09-29 00:24:17.868596 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2025-09-29 00:24:17.876616 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2025-09-29 00:24:17.8809 DEBUG::tools.R/processChunks: starting...
2025-09-29 00:24:23.213116 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-09-29 00:24:23.216155 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-09-29 00:24:26.609766 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.057 minutes
2025-09-29 00:24:26.684978 DEBUG::tools.R/processChunks: done
2025-09-29 00:24:26.688923 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-09-29 00:24:26.69159 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-09-29 00:24:26.694776 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-09-29 00:24:26.69718 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-09-29 00:24:26.707718 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
2025-09-29 00:24:26.711162 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-09-29 00:24:26.715009 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-09-29 00:24:26.722973 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-09-29 00:24:26.73061 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-09-29 00:25:17.746166 DEBUG::tools.R/traceMem: wired.mem=19.303002 GiB
2025-09-29 00:26:17.811964 DEBUG::tools.R/traceMem: wired.mem=14.955278 GiB
2025-09-29 00:27:17.878471 DEBUG::tools.R/traceMem: wired.mem=18.527711 GiB
2025-09-29 00:28:17.947227 DEBUG::tools.R/traceMem: wired.mem=24.693617 GiB
2025-09-29 00:29:18.013324 DEBUG::tools.R/traceMem: wired.mem=25.086579 GiB
2025-09-29 00:30:18.080747 DEBUG::tools.R/traceMem: wired.mem=23.031402 GiB
2025-09-29 00:31:18.147862 DEBUG::tools.R/traceMem: wired.mem=27.339141 GiB
2025-09-29 00:32:18.213155 DEBUG::tools.R/traceMem: wired.mem=27.307561 GiB
2025-09-29 00:33:18.278167 DEBUG::tools.R/traceMem: wired.mem=32.439185 GiB
2025-09-29 00:34:18.337826 DEBUG::tools.R/traceMem: wired.mem=20.019638 GiB
2025-09-29 00:35:18.404508 DEBUG::tools.R/traceMem: wired.mem=22.864998 GiB
2025-09-29 00:36:18.469971 DEBUG::tools.R/traceMem: wired.mem=23.761842 GiB
2025-09-29 00:37:18.534821 DEBUG::tools.R/traceMem: wired.mem=23.862456 GiB
2025-09-29 00:38:18.599973 DEBUG::tools.R/traceMem: wired.mem=21.414785 GiB
2025-09-29 00:39:18.6657 DEBUG::tools.R/traceMem: wired.mem=25.427161 GiB
2025-09-29 00:40:18.731156 DEBUG::tools.R/traceMem: wired.mem=27.020030 GiB
2025-09-29 00:41:18.799028 DEBUG::tools.R/traceMem: wired.mem=25.851515 GiB
2025-09-29 00:42:18.865817 DEBUG::tools.R/traceMem: wired.mem=18.389643 GiB
2025-09-29 00:43:18.930551 DEBUG::tools.R/traceMem: wired.mem=14.899728 GiB
2025-09-29 00:44:18.995574 DEBUG::tools.R/traceMem: wired.mem=14.918971 GiB
2025-09-29 00:45:19.063889 DEBUG::tools.R/traceMem: wired.mem=18.863927 GiB
2025-09-29 00:46:19.129217 DEBUG::tools.R/traceMem: wired.mem=32.239374 GiB
2025-09-29 00:47:19.19566 DEBUG::tools.R/traceMem: wired.mem=25.638818 GiB
2025-09-29 00:48:19.262019 DEBUG::tools.R/traceMem: wired.mem=23.090262 GiB
2025-09-29 00:49:19.328921 DEBUG::tools.R/traceMem: wired.mem=24.337576 GiB
2025-09-29 00:50:19.396021 DEBUG::tools.R/traceMem: wired.mem=26.665292 GiB
2025-09-29 00:51:19.462141 DEBUG::tools.R/traceMem: wired.mem=18.657735 GiB
2025-09-29 00:52:19.529722 DEBUG::tools.R/traceMem: wired.mem=26.501403 GiB
2025-09-29 00:53:19.596016 DEBUG::tools.R/traceMem: wired.mem=21.933371 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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