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"	4833
merida1	macOS 12.7.6 Monterey	x86_64	4.5.1 RC (2025-06-05 r88288) -- "Great Square Root"	4614
kjohnson1	macOS 13.7.5 Ventura	arm64	4.5.1 Patched (2025-06-14 r88325) -- "Great Square Root"	4555
kunpeng2	Linux (openEuler 24.03 LTS)	aarch64	R Under development (unstable) (2025-02-19 r87757) -- "Unsuffered Consequences"	4586
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-10-16 00:09:17 -0400 (Thu, 16 Oct 2025)

EndedAt: 2025-10-16 00:49:18 -0400 (Thu, 16 Oct 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/Rtmp5GRC6e/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-10-16 00:14:52.445753 INFO::preprocessReads.R/preprocessReads: starting...
2025-10-16 00:14:52.453658 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-10-16 00:14:52.457102 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-10-16 00:14:52.459297 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:14:55.140824 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:14:55.142267 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/chunks/chunk_000001/logs/progress.log
2025-10-16 00:14:57.890953 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-10-16 00:14:57.892421 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/chunks/chunk_000002/logs/progress.log
2025-10-16 00:15:00.647475 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-10-16 00:15:00.649437 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/chunks/chunk_000003/logs/progress.log
2025-10-16 00:15:03.35977 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-10-16 00:15:03.389072 DEBUG::tools.R/processChunks: done
2025-10-16 00:15:03.392733 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:15:03.394826 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/results/test_pe.adapter_contaminated_1.RData
2025-10-16 00:15:03.397394 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-10-16 00:15:03.398921 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/results/test_pe.adapter_contaminated_2.RData
2025-10-16 00:15:03.40788 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-10-16 00:15:03.410206 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/results/test_pe.summary_preprocess.tab
2025-10-16 00:15:03.413635 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/bams/processed.aligner_input_1.fastq ...
2025-10-16 00:15:03.417964 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/bams/processed.aligner_input_2.fastq ...
2025-10-16 00:15:03.421475 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/reports/shortReadReport_1 ...
2025-10-16 00:15:04.752028 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/reports/shortReadReport_2 ...
2025-10-16 00:15:07.269629 INFO::preprocessReads.R/preprocessReads: done
2025-10-16 00:15:07.337725 INFO::alignReads.R/alignReads: starting alignment...
2025-10-16 00:15:07.343846 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:15:10.345659 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:15:10.347423 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/chunks/chunk_000001/logs/progress.log
2025-10-16 00:15:13.200293 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2025-10-16 00:15:13.20203 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/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-10-16 00:15:15.88904 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-10-16 00:15:15.890764 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/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-10-16 00:15:18.542041 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-10-16 00:15:18.544948 DEBUG::tools.R/processChunks: done
2025-10-16 00:15:18.546643 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-10-16 00:15:18.763756 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-10-16 00:15:18.77179 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/results/test_pe.summary_alignment.tab
2025-10-16 00:15:18.778583 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/results/test_pe.summary_analyzed_bamstats.tab
2025-10-16 00:15:18.780203 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-10-16 00:15:19.014843 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.a4620480c0eec/results/test_pe.summary_target_lengths.tab
2025-10-16 00:15:19.060691 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-10-16 00:15:19.061762 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:15:19.305423 INFO::preprocessReads.R/preprocessReads: starting...
2025-10-16 00:15:19.308673 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-10-16 00:15:19.373885 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-10-16 00:15:19.378811 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-10-16 00:15:19.381887 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-10-16 00:15:19.383995 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:15:22.573869 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:15:22.575321 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/chunks/chunk_000001/logs/progress.log
2025-10-16 00:15:25.299215 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-10-16 00:15:25.300719 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/chunks/chunk_000002/logs/progress.log
2025-10-16 00:15:27.997371 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-10-16 00:15:27.998814 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/chunks/chunk_000003/logs/progress.log
2025-10-16 00:15:30.79391 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2025-10-16 00:15:30.795371 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/chunks/chunk_000004/logs/progress.log
2025-10-16 00:15:33.461498 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2025-10-16 00:15:33.501992 DEBUG::tools.R/processChunks: done
2025-10-16 00:15:33.506827 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:15:33.510286 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/results/test_pe.adapter_contaminated_1.RData
2025-10-16 00:15:33.514784 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-10-16 00:15:33.517567 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/results/test_pe.adapter_contaminated_2.RData
2025-10-16 00:15:33.532515 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-10-16 00:15:33.535803 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/results/test_pe.summary_preprocess.tab
2025-10-16 00:15:33.540983 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/bams/processed.aligner_input_1.fastq ...
2025-10-16 00:15:33.547046 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/bams/processed.aligner_input_2.fastq ...
2025-10-16 00:15:33.551448 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/reports/shortReadReport_1 ...
2025-10-16 00:15:34.817724 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.alignReads.sparsechunks.a46203e37e058/reports/shortReadReport_2 ...
2025-10-16 00:15:37.056915 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:15:37.252124 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-10-16 00:15:37.262647 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/Rtmp5GRC6e/test.alignReadsOneSingleEnd.a4620535b4fe4/bams/test.alignReads /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-10-16 00:15:37.554853 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-10-16 00:15:37.649275 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReadsOneSingleEnd.a4620535b4fe4/results/test.alignReads.summary_alignment.tab
2025-10-16 00:15:37.698913 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.alignReadsOneSingleEnd.a4620535b4fe4/results/test.alignReads.summary_analyzed_bamstats.tab
2025-10-16 00:15:37.700408 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.001 0.001 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/Rtmp5GRC6e/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-10-16 00:15:38.014025 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.genotype.a46201838e6e5/results/test_pe.coverage.RData
2025-10-16 00:15:38.015801 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5GRC6e/test.genotype.a46201838e6e5/results/test_pe.coverage.bw
2025-10-16 00:15:38.125258 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.genotype.a46201838e6e5/results/test_pe.summary_coverage.tab
2025-10-16 00:15:38.12686 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-10-16 00:15:47.606811 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-10-16 00:15:47.694663 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-10-16 00:15:47.71825 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-10-16 00:15:47.72006 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.genotype.a46201838e6e5/results/test_pe.raw_variants.RData
2025-10-16 00:15:47.722603 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.genotype.a46201838e6e5/results/test_pe.filtered_variants.RData
2025-10-16 00:15:47.724006 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-10-16 00:15:47.725193 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-10-16 00:15:48.137598 INFO::analyzeVariants.R/writeVCF: ...done
2025-10-16 00:15:48.138894 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-10-16 00:16:51.170362 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-10-16 00:16:51.545448 INFO::analyzeVariants.R/writeVCF: ...done
2025-10-16 00:16:51.546396 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/Rtmp5GRC6e/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-10-16 00:16:51.998449 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-10-16 00:17:01.760589 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-10-16 00:17:01.83942 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-10-16 00:17:01.856817 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-10-16 00:17:01.858264 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.a46206fe64449/results/test_pe.raw_variants.RData
2025-10-16 00:17:01.860867 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.a46206fe64449/results/test_pe.filtered_variants.RData
2025-10-16 00:17:01.862248 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:17:02.01584 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-10-16 00:17:11.490034 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-10-16 00:17:11.55201 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-10-16 00:17:11.570151 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-10-16 00:17:11.571614 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.filters.a46201b13ebcf/results/test_pe.raw_variants.RData
2025-10-16 00:17:11.574153 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.filters.a46201b13ebcf/results/test_pe.filtered_variants.RData
2025-10-16 00:17:11.57545 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-10-16 00:17:11.576979 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-10-16 00:17:20.878704 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-10-16 00:17:20.919349 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-10-16 00:17:20.937304 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-10-16 00:17:20.938758 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.filters.a46201b13ebcf/results/test_pe.raw_variants.RData
2025-10-16 00:17:20.941315 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.filters.a46201b13ebcf/results/test_pe.filtered_variants.RData
2025-10-16 00:17:20.943329 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:17:21.173498 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-10-16 00:17:21.174935 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-10-16 00:17:23.829994 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-10-16 00:17:23.904812 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-10-16 00:17:23.921386 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-10-16 00:17:23.922743 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.which.a46204c3d1ef7/results/test_pe.raw_variants.RData
2025-10-16 00:17:23.924351 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.wrap.callVariants.which.a46204c3d1ef7/results/test_pe.filtered_variants.RData
2025-10-16 00:17:23.925547 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:17:24.061915 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-10-16 00:17:24.063164 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:17:24.237895 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-10-16 00:17:24.439923 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-10-16 00:18:15.856122 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/ydrmounc/merged/results/bla.coverage.RData
2025-10-16 00:18:15.857829 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5GRC6e/ydrmounc/merged/results/bla.coverage.bw
2025-10-16 00:18:15.947789 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/ydrmounc/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-10-16 00:18:17.172084 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/xraemiuh/merged/results/bla.coverage.RData
2025-10-16 00:18:17.174099 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5GRC6e/xraemiuh/merged/results/bla.coverage.bw
2025-10-16 00:18:17.186028 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/xraemiuh/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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/Rtmp5GRC6e/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-10-16 00:18:18.427336 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-10-16 00:18:18.428466 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp5GRC6e/test.detectRRNA.a46203cdadc49/bams/rRNA_contam/input1.fastq
2025-10-16 00:18:18.431738 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/Rtmp5GRC6e/test.detectRRNA.a46203cdadc49/bams/rRNA_contam/test_se /tmp/Rtmp5GRC6e/test.detectRRNA.a46203cdadc49/bams/rRNA_contam/input1.fastq 2>&1
2025-10-16 00:18:18.609032 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-10-16 00:18:18.610049 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:18:18.762664 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-10-16 00:18:18.763667 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp5GRC6e/test.detectRRNA.paired_end.a462059358f26/bams/rRNA_contam/input1.fastq
2025-10-16 00:18:18.765145 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp5GRC6e/test.detectRRNA.paired_end.a462059358f26/bams/rRNA_contam/input2.fastq
2025-10-16 00:18:18.767238 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/Rtmp5GRC6e/test.detectRRNA.paired_end.a462059358f26/bams/rRNA_contam/test_pe /tmp/Rtmp5GRC6e/test.detectRRNA.paired_end.a462059358f26/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp5GRC6e/test.detectRRNA.paired_end.a462059358f26/bams/rRNA_contam/input2.fastq 2>&1
2025-10-16 00:18:19.004566 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-10-16 00:18:19.005669 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-10-16 00:18:19.02518 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/Rtmp5GRC6e/test_get_rRNA_idsnhcjqkbl/test_pe /tmp/Rtmp5GRC6e/test_get_rRNA_idsnhcjqkbl/1.fastq -a paired /tmp/Rtmp5GRC6e/test_get_rRNA_idsnhcjqkbl/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-10-16 00:18:19.266913 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/Rtmp5GRC6e/test_get_rRNAIds_randomcgpqanyb/test_pe /tmp/Rtmp5GRC6e/test_get_rRNAIds_randomcgpqanyb/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-10-16 00:18:19.530589 INFO::filterQuality.R/filterQuality: filterByLength...
2025-10-16 00:18:19.532197 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-10-16 00:18:19.533189 INFO::filterQuality.R/filterByLength: done
2025-10-16 00:18:19.580957 INFO::filterQuality.R/filterQuality: filterByLength...
2025-10-16 00:18:19.581931 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-10-16 00:18:19.582757 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-10-16 00:18:19.63352 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-10-16 00:18:19.642334 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-10-16 00:18:19.643377 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-10-16 00:18:19.647838 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-10-16 00:18:19.648833 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-10-16 00:18:19.65324 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-10-16 00:18:19.65417 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-10-16 00:18:19.658532 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsGATK.withFiltering  ... Timing stopped at: 0 0 0.001
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.001
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/Rtmp5GRC6e/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-10-16 00:18:19.932184 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-10-16 00:18:19.934712 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/Rtmp5GRC6e/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-10-16 00:18:20.120652 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-10-16 00:18:20.193911 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-10-16 00:18:20.197045 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-10-16 00:18:20.19969 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/Rtmp5GRC6e/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-10-16 00:18:20.406554 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/Rtmp5GRC6e/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-10-16 00:18:20.553105 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/Rtmp5GRC6e/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-10-16 00:18:20.690423 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-10-16 00:18:20.734764 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-10-16 00:18:20.737215 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-10-16 00:18:20.739428 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/Rtmp5GRC6e/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-10-16 00:18:20.953637 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-10-16 00:18:20.96904 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-10-16 00:18:20.971478 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-10-16 00:18:20.97373 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/Rtmp5GRC6e/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/Rtmp5GRC6e/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-10-16 00:18:21.724173 INFO::preprocessReads.R/preprocessReads: starting...
2025-10-16 00:18:21.729799 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-10-16 00:18:21.733022 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-10-16 00:18:21.735233 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:18:24.786322 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:18:24.787826 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000001/logs/progress.log
2025-10-16 00:18:27.425192 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-10-16 00:18:27.426773 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000002/logs/progress.log
2025-10-16 00:18:30.058983 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-10-16 00:18:30.060585 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000003/logs/progress.log
2025-10-16 00:18:32.7027 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-10-16 00:18:32.754427 DEBUG::tools.R/processChunks: done
2025-10-16 00:18:32.757995 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:18:32.760034 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.adapter_contaminated_1.RData
2025-10-16 00:18:32.762498 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-10-16 00:18:32.764189 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.adapter_contaminated_2.RData
2025-10-16 00:18:32.773054 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-10-16 00:18:32.774993 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.summary_preprocess.tab
2025-10-16 00:18:32.777586 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/bams/processed.aligner_input_1.fastq ...
2025-10-16 00:18:32.782112 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/bams/processed.aligner_input_2.fastq ...
2025-10-16 00:18:32.786372 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/reports/shortReadReport_1 ...
2025-10-16 00:18:34.090938 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/reports/shortReadReport_2 ...
2025-10-16 00:18:35.162954 INFO::preprocessReads.R/preprocessReads: done
2025-10-16 00:18:35.278408 INFO::alignReads.R/alignReads: starting alignment...
2025-10-16 00:18:35.28293 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:18:38.124964 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:18:38.126538 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000001/logs/progress.log
2025-10-16 00:18:40.705878 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-10-16 00:18:40.707448 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/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-10-16 00:18:43.357163 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-10-16 00:18:43.358997 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/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-10-16 00:18:46.021935 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-10-16 00:18:46.024209 DEBUG::tools.R/processChunks: done
2025-10-16 00:18:46.02552 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-10-16 00:18:46.215613 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-10-16 00:18:46.223421 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.summary_alignment.tab
2025-10-16 00:18:46.230559 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.summary_analyzed_bamstats.tab
2025-10-16 00:18:46.23261 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-10-16 00:18:46.449926 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.summary_target_lengths.tab
2025-10-16 00:18:46.494602 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-10-16 00:18:46.495602 INFO::alignReads.R/alignReads: done
2025-10-16 00:18:46.617179 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-10-16 00:18:46.639167 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:18:49.570506 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:18:49.572265 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000001/logs/progress.log
2025-10-16 00:18:52.052378 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-10-16 00:18:52.054016 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000002/logs/progress.log
2025-10-16 00:18:54.511545 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2025-10-16 00:18:54.513151 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000003/logs/progress.log
2025-10-16 00:18:56.962731 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2025-10-16 00:18:56.966213 DEBUG::tools.R/processChunks: done
2025-10-16 00:18:56.968466 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-10-16 00:18:56.986999 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.counts_exon.tab
2025-10-16 00:18:57.002122 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.counts_exon_disjoint.tab
2025-10-16 00:18:57.011705 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.counts_gene.tab
2025-10-16 00:18:57.018742 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.counts_gene_coding.tab
2025-10-16 00:18:57.02549 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.counts_gene_exonic.tab
2025-10-16 00:18:57.032491 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.counts_intergenic.tab
2025-10-16 00:18:57.045599 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.counts_intron.tab
2025-10-16 00:18:57.048675 INFO::countGenomicFeatures.R/mergeCounts: done
2025-10-16 00:18:57.054019 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.summary_counts.tab
2025-10-16 00:18:57.055556 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-10-16 00:18:57.351439 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-10-16 00:18:57.352365 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-10-16 00:18:57.463121 INFO::coverage.R/calculateCoverage: starting...
2025-10-16 00:18:57.467407 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:19:00.674186 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:19:00.675894 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000001/logs/progress.log
2025-10-16 00:19:02.843958 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2025-10-16 00:19:02.846545 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000002/logs/progress.log
2025-10-16 00:19:05.059813 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2025-10-16 00:19:05.061629 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/chunks/chunk_000003/logs/progress.log
2025-10-16 00:19:07.242071 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2025-10-16 00:19:07.244415 DEBUG::tools.R/processChunks: done
2025-10-16 00:19:08.581893 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.coverage.RData
2025-10-16 00:19:08.583397 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.coverage.bw
2025-10-16 00:19:08.594728 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.summary_coverage.tab
2025-10-16 00:19:08.595973 INFO::coverage.R/calculateCoverage: done
2025-10-16 00:19:08.598417 INFO::analyzeVariants/analyzeVariants: starting ...
2025-10-16 00:19:08.701833 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-10-16 00:19:11.876567 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-10-16 00:19:11.976246 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-10-16 00:19:11.998383 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-10-16 00:19:12.000109 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.raw_variants.RData
2025-10-16 00:19:12.002423 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.filtered_variants.RData
2025-10-16 00:19:12.003966 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-10-16 00:19:12.005147 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-10-16 00:19:12.302342 INFO::analyzeVariants.R/writeVCF: ...done
2025-10-16 00:19:12.432546 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/results/test_pe.summary_variants.tab
2025-10-16 00:19:12.440359 INFO::analyzeVariants/analyzeVariants: done
2025-10-16 00:19:12.445656 INFO::Pipeline run successful.
2025-10-16 00:19:12.664432 INFO::mergeLanes.R/doMergeLanes: starting...
2025-10-16 00:19:12.669483 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:19:12.671847 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.adapter_contaminated_1.RData
2025-10-16 00:19:12.675069 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-10-16 00:19:12.677205 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.adapter_contaminated_2.RData
2025-10-16 00:19:12.689506 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-10-16 00:19:12.691999 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.summary_preprocess.tab
2025-10-16 00:19:12.694328 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-10-16 00:19:12.942977 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-10-16 00:19:12.950555 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.summary_alignment.tab
2025-10-16 00:19:12.958839 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.summary_analyzed_bamstats.tab
2025-10-16 00:19:12.96105 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-10-16 00:19:13.202832 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.summary_target_lengths.tab
2025-10-16 00:19:13.253666 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-10-16 00:19:13.30793 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-10-16 00:19:13.329636 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.counts_exon.tab
2025-10-16 00:19:13.342196 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.counts_exon_disjoint.tab
2025-10-16 00:19:13.34946 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.counts_gene.tab
2025-10-16 00:19:13.355603 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.counts_gene_coding.tab
2025-10-16 00:19:13.36097 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.counts_gene_exonic.tab
2025-10-16 00:19:13.366709 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.counts_intergenic.tab
2025-10-16 00:19:13.378565 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.counts_intron.tab
2025-10-16 00:19:13.381365 INFO::countGenomicFeatures.R/mergeCounts: done
2025-10-16 00:19:13.387782 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.summary_counts.tab
2025-10-16 00:19:13.389678 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-10-16 00:19:13.633761 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-10-16 00:19:15.674022 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.coverage.RData
2025-10-16 00:19:15.676749 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.coverage.bw
2025-10-16 00:19:15.68877 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.summary_coverage.tab
2025-10-16 00:19:15.733031 INFO::analyzeVariants/analyzeVariants: starting ...
2025-10-16 00:19:15.837204 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-10-16 00:19:18.897555 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-10-16 00:19:18.970005 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-10-16 00:19:18.98617 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-10-16 00:19:18.987514 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.raw_variants.RData
2025-10-16 00:19:18.989073 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.filtered_variants.RData
2025-10-16 00:19:18.990327 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-10-16 00:19:18.991268 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-10-16 00:19:19.203155 INFO::analyzeVariants.R/writeVCF: ...done
2025-10-16 00:19:19.299557 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.mergeLanes.a46202651750a/merged/results/merged.summary_variants.tab
2025-10-16 00:19:19.301524 INFO::analyzeVariants/analyzeVariants: done
2025-10-16 00:19:19.305034 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:19:19.668893 INFO::preprocessReads.R/preprocessReads: starting...
2025-10-16 00:19:19.689235 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-10-16 00:19:19.703311 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-10-16 00:19:19.706187 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:19:23.373003 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:19:23.374982 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/chunks/chunk_000001/logs/progress.log
2025-10-16 00:19:26.663127 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.055 minutes
2025-10-16 00:19:26.783869 DEBUG::tools.R/processChunks: done
2025-10-16 00:19:26.787369 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:19:26.789692 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/results/test_pe.adapter_contaminated_1.RData
2025-10-16 00:19:26.792472 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-10-16 00:19:26.794537 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/results/test_pe.adapter_contaminated_2.RData
2025-10-16 00:19:26.804774 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-10-16 00:19:26.807801 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/results/test_pe.summary_preprocess.tab
2025-10-16 00:19:26.811209 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/bams/processed.aligner_input_1.fastq ...
2025-10-16 00:19:26.823996 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/bams/processed.aligner_input_2.fastq ...
2025-10-16 00:19:26.839059 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/reports/shortReadReport_1 ...
2025-10-16 00:19:30.680221 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.preprocessReads.a4620da911c3/reports/shortReadReport_2 ...
2025-10-16 00:19:33.111243 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:19:34.05699 INFO::preprocessReads.R/preprocessReads: starting...
2025-10-16 00:19:34.079681 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-10-16 00:19:34.097604 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-10-16 00:19:34.103742 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:19:42.921559 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:19:42.926961 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/chunks/chunk_000001/logs/progress.log
2025-10-16 00:19:46.855729 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.065 minutes
2025-10-16 00:19:46.865804 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/chunks/chunk_000002/logs/progress.log
2025-10-16 00:19:50.259892 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.057 minutes
2025-10-16 00:19:50.26378 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/chunks/chunk_000003/logs/progress.log
2025-10-16 00:19:52.909984 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-10-16 00:19:52.950506 DEBUG::tools.R/processChunks: done
2025-10-16 00:19:52.953173 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:19:52.954735 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/results/test_pe.adapter_contaminated_1.RData
2025-10-16 00:19:52.956702 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-10-16 00:19:52.958045 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/results/test_pe.adapter_contaminated_2.RData
2025-10-16 00:19:52.965148 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-10-16 00:19:52.966845 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/results/test_pe.summary_preprocess.tab
2025-10-16 00:19:52.96903 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/bams/processed.aligner_input_1.fastq ...
2025-10-16 00:19:52.972844 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/bams/processed.aligner_input_2.fastq ...
2025-10-16 00:19:52.976557 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/reports/shortReadReport_1 ...
2025-10-16 00:19:55.459552 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.preprocessReads.minichunks.a4620330228b7/reports/shortReadReport_2 ...
2025-10-16 00:19:57.471577 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp5GRC6e/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-10-16 00:19:58.114208 INFO::preprocessReads.R/preprocessReads: starting...
2025-10-16 00:19:58.153829 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-10-16 00:19:58.160151 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:20:05.539408 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:20:05.544124 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp5GRC6e/test.preprocessReads_single_end.a46203043e77e/chunks/chunk_000001/logs/progress.log
2025-10-16 00:20:08.419146 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2025-10-16 00:20:08.512431 DEBUG::tools.R/processChunks: done
2025-10-16 00:20:08.517732 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:20:08.521636 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads_single_end.a46203043e77e/results/test_se.adapter_contaminated_1.RData
2025-10-16 00:20:08.539951 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-10-16 00:20:08.544554 INFO::io.R/saveWithID: saving file= /tmp/Rtmp5GRC6e/test.preprocessReads_single_end.a46203043e77e/results/test_se.summary_preprocess.tab
2025-10-16 00:20:08.549677 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp5GRC6e/test.preprocessReads_single_end.a46203043e77e/bams/processed.aligner_input_1.fastq ...
2025-10-16 00:20:08.558287 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp5GRC6e/test.preprocessReads_single_end.a46203043e77e/reports/shortReadReport_1 ...
2025-10-16 00:20:11.196032 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-10-16 00:20:12.272322 INFO::preprocessReads.R/preprocessReads: starting...
2025-10-16 00:20:12.298731 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-10-16 00:20:12.304951 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-10-16 00:20:12.308633 DEBUG::tools.R/processChunks: starting...
2025-10-16 00:20:16.735596 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-10-16 00:20:16.737266 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-10-16 00:20:19.604983 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2025-10-16 00:20:19.678113 DEBUG::tools.R/processChunks: done
2025-10-16 00:20:19.682378 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-10-16 00:20:19.68513 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-10-16 00:20:19.688204 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-10-16 00:20:19.690514 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-10-16 00:20:19.70091 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-10-16 00:20:19.704025 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-10-16 00:20:19.707606 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-10-16 00:20:19.713722 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-10-16 00:20:19.719382 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-10-16 00:21:12.240283 DEBUG::tools.R/traceMem: wired.mem=-6.429438 GiB
2025-10-16 00:22:12.308135 DEBUG::tools.R/traceMem: wired.mem=-18.196074 GiB
2025-10-16 00:23:12.375817 DEBUG::tools.R/traceMem: wired.mem=-6.796390 GiB
2025-10-16 00:24:12.442796 DEBUG::tools.R/traceMem: wired.mem=-4.927271 GiB
2025-10-16 00:25:12.507438 DEBUG::tools.R/traceMem: wired.mem=-0.861737 GiB
2025-10-16 00:26:12.574689 DEBUG::tools.R/traceMem: wired.mem=4.261655 GiB
2025-10-16 00:27:12.639848 DEBUG::tools.R/traceMem: wired.mem=1.973981 GiB
2025-10-16 00:28:12.706665 DEBUG::tools.R/traceMem: wired.mem=5.282148 GiB
2025-10-16 00:29:12.772316 DEBUG::tools.R/traceMem: wired.mem=-6.159356 GiB
2025-10-16 00:30:12.811947 DEBUG::tools.R/traceMem: wired.mem=-9.306190 GiB
2025-10-16 00:31:12.879365 DEBUG::tools.R/traceMem: wired.mem=3.392582 GiB
2025-10-16 00:32:12.944757 DEBUG::tools.R/traceMem: wired.mem=-4.084421 GiB
2025-10-16 00:33:13.010526 DEBUG::tools.R/traceMem: wired.mem=-3.522220 GiB
2025-10-16 00:34:13.076354 DEBUG::tools.R/traceMem: wired.mem=6.584381 GiB
2025-10-16 00:35:13.141155 DEBUG::tools.R/traceMem: wired.mem=-4.105417 GiB
2025-10-16 00:36:13.208231 DEBUG::tools.R/traceMem: wired.mem=6.961795 GiB
2025-10-16 00:37:13.27455 DEBUG::tools.R/traceMem: wired.mem=-0.124219 GiB
2025-10-16 00:38:13.340101 DEBUG::tools.R/traceMem: wired.mem=-4.625207 GiB
2025-10-16 00:39:13.406601 DEBUG::tools.R/traceMem: wired.mem=-9.024541 GiB
2025-10-16 00:40:13.471722 DEBUG::tools.R/traceMem: wired.mem=-10.753307 GiB
2025-10-16 00:41:13.53643 DEBUG::tools.R/traceMem: wired.mem=-0.406966 GiB
2025-10-16 00:42:13.601932 DEBUG::tools.R/traceMem: wired.mem=1.518531 GiB
2025-10-16 00:43:13.669064 DEBUG::tools.R/traceMem: wired.mem=2.372891 GiB
2025-10-16 00:44:13.730341 DEBUG::tools.R/traceMem: wired.mem=-3.691041 GiB
2025-10-16 00:45:13.79749 DEBUG::tools.R/traceMem: wired.mem=0.779882 GiB
2025-10-16 00:46:13.864111 DEBUG::tools.R/traceMem: wired.mem=3.614036 GiB
2025-10-16 00:47:13.93148 DEBUG::tools.R/traceMem: wired.mem=10.073051 GiB
2025-10-16 00:48:13.997543 DEBUG::tools.R/traceMem: wired.mem=2.647691 GiB
2025-10-16 00:49:14.062867 DEBUG::tools.R/traceMem: wired.mem=1.876799 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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