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.1 LTS)	x86_64	R Under development (unstable) (2025-03-13 r87965) -- "Unsuffered Consequences"	4783
palomino7	Windows Server 2022 Datacenter	x64	R Under development (unstable) (2025-03-01 r87860 ucrt) -- "Unsuffered Consequences"	4552
lconway	macOS 12.7.1 Monterey	x86_64	R Under development (unstable) (2025-03-02 r87868) -- "Unsuffered Consequences"	4581
kjohnson3	macOS 13.7.1 Ventura	arm64	R Under development (unstable) (2025-03-02 r87868) -- "Unsuffered Consequences"	4533
kunpeng2	Linux (openEuler 24.03 LTS)	aarch64	R Under development (unstable) (2025-02-19 r87757) -- "Unsuffered Consequences"	4463
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.37.1

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.37.1.tar.gz

StartedAt: 2025-03-26 23:16:33 -0400 (Wed, 26 Mar 2025)

EndedAt: 2025-03-26 23:56:34 -0400 (Wed, 26 Mar 2025)

EllapsedTime: 2400.5 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.37.1.tar.gz
###
##############################################################################
##############################################################################


* using log directory ‘/home/biocbuild/bbs-3.21-bioc/meat/HTSeqGenie.Rcheck’
* using R Under development (unstable) (2025-03-13 r87965)
* 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.2 LTS
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.37.1’
* 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.37.1’
** 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 Under development (unstable) (2025-03-13 r87965) -- "Unsuffered Consequences"
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/RtmpZpALYv/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-03-26 23:22:03.01766 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-26 23:22:03.027971 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-03-26 23:22:03.032765 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-03-26 23:22:03.035611 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:22:06.008183 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:22:06.009593 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/chunks/chunk_000001/logs/progress.log
2025-03-26 23:22:08.758828 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-03-26 23:22:08.760429 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/chunks/chunk_000002/logs/progress.log
2025-03-26 23:22:11.478583 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-03-26 23:22:11.480059 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/chunks/chunk_000003/logs/progress.log
2025-03-26 23:22:14.198602 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-26 23:22:14.231908 DEBUG::tools.R/processChunks: done
2025-03-26 23:22:14.236 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:22:14.238245 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/results/test_pe.adapter_contaminated_1.RData
2025-03-26 23:22:14.240998 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-26 23:22:14.242637 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/results/test_pe.adapter_contaminated_2.RData
2025-03-26 23:22:14.25169 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-03-26 23:22:14.253992 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/results/test_pe.summary_preprocess.tab
2025-03-26 23:22:14.257312 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/bams/processed.aligner_input_1.fastq ...
2025-03-26 23:22:14.261275 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/bams/processed.aligner_input_2.fastq ...
2025-03-26 23:22:14.264459 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/reports/shortReadReport_1 ...
2025-03-26 23:22:15.604136 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/reports/shortReadReport_2 ...
2025-03-26 23:22:18.126584 INFO::preprocessReads.R/preprocessReads: done
2025-03-26 23:22:18.194894 INFO::alignReads.R/alignReads: starting alignment...
2025-03-26 23:22:18.200437 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:22:21.014225 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:22:21.015738 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/chunks/chunk_000001/logs/progress.log
2025-03-26 23:22:23.788154 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-03-26 23:22:23.789844 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/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-03-26 23:22:26.447254 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-26 23:22:26.449053 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/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-03-26 23:22:29.141493 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-26 23:22:29.144157 DEBUG::tools.R/processChunks: done
2025-03-26 23:22:29.145563 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-03-26 23:22:29.369969 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-26 23:22:29.378079 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/results/test_pe.summary_alignment.tab
2025-03-26 23:22:29.385055 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/results/test_pe.summary_analyzed_bamstats.tab
2025-03-26 23:22:29.386619 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-26 23:22:29.634546 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.1bb37c6a5e5bff/results/test_pe.summary_target_lengths.tab
2025-03-26 23:22:29.680544 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-26 23:22:29.681526 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:22:29.946813 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-26 23:22:29.950282 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-03-26 23:22:30.020893 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-03-26 23:22:30.025945 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-03-26 23:22:30.029134 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-03-26 23:22:30.031228 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:22:33.165808 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:22:33.167293 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/chunks/chunk_000001/logs/progress.log
2025-03-26 23:22:35.877828 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-03-26 23:22:35.879176 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/chunks/chunk_000002/logs/progress.log
2025-03-26 23:22:38.599478 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-03-26 23:22:38.60119 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/chunks/chunk_000003/logs/progress.log
2025-03-26 23:22:41.359742 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-03-26 23:22:41.361423 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/chunks/chunk_000004/logs/progress.log
2025-03-26 23:22:44.067452 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2025-03-26 23:22:44.112848 DEBUG::tools.R/processChunks: done
2025-03-26 23:22:44.116144 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:22:44.118563 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/results/test_pe.adapter_contaminated_1.RData
2025-03-26 23:22:44.121728 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-26 23:22:44.123534 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/results/test_pe.adapter_contaminated_2.RData
2025-03-26 23:22:44.133963 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-03-26 23:22:44.136148 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/results/test_pe.summary_preprocess.tab
2025-03-26 23:22:44.139674 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/bams/processed.aligner_input_1.fastq ...
2025-03-26 23:22:44.144677 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/bams/processed.aligner_input_2.fastq ...
2025-03-26 23:22:44.147751 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/reports/shortReadReport_1 ...
2025-03-26 23:22:45.486406 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.alignReads.sparsechunks.1bb37c5b6b20d4/reports/shortReadReport_2 ...
2025-03-26 23:22:47.968779 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:22:48.163704 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-03-26 23:22:48.167835 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/RtmpZpALYv/test.alignReadsOneSingleEnd.1bb37c101d2170/bams/test.alignReads /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-03-26 23:22:48.419299 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-03-26 23:22:48.511062 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReadsOneSingleEnd.1bb37c101d2170/results/test.alignReads.summary_alignment.tab
2025-03-26 23:22:48.562687 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.alignReadsOneSingleEnd.1bb37c101d2170/results/test.alignReads.summary_analyzed_bamstats.tab
2025-03-26 23:22:48.56427 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:22:48.883485 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.genotype.1bb37c542a419e/results/test_pe.coverage.RData
2025-03-26 23:22:48.885654 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpZpALYv/test.genotype.1bb37c542a419e/results/test_pe.coverage.bw
2025-03-26 23:22:49.005832 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.genotype.1bb37c542a419e/results/test_pe.summary_coverage.tab
2025-03-26 23:22:49.007604 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-26 23:22:58.631491 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-26 23:22:58.722974 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-26 23:22:58.741225 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-26 23:22:58.742972 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.genotype.1bb37c542a419e/results/test_pe.raw_variants.RData
2025-03-26 23:22:58.745598 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.genotype.1bb37c542a419e/results/test_pe.filtered_variants.RData
2025-03-26 23:22:58.747115 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-26 23:22:58.748428 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-26 23:22:59.203058 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-26 23:22:59.204324 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-03-26 23:24:01.056702 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-26 23:24:01.494004 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-26 23:24:01.4949 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/RtmpZpALYv/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-03-26 23:24:01.939336 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-26 23:24:11.70804 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-26 23:24:11.784912 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-26 23:24:11.801198 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-26 23:24:11.802581 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.1bb37c54bd03fb/results/test_pe.raw_variants.RData
2025-03-26 23:24:11.805117 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.1bb37c54bd03fb/results/test_pe.filtered_variants.RData
2025-03-26 23:24:11.806455 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:24:11.951603 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-26 23:24:21.040663 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-26 23:24:21.102675 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-26 23:24:21.120943 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-26 23:24:21.122528 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.filters.1bb37c23f5a347/results/test_pe.raw_variants.RData
2025-03-26 23:24:21.125181 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.filters.1bb37c23f5a347/results/test_pe.filtered_variants.RData
2025-03-26 23:24:21.126582 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-26 23:24:21.128496 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-26 23:24:30.45775 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-26 23:24:30.497953 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-26 23:24:30.515338 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-26 23:24:30.516873 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.filters.1bb37c23f5a347/results/test_pe.raw_variants.RData
2025-03-26 23:24:30.519679 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.filters.1bb37c23f5a347/results/test_pe.filtered_variants.RData
2025-03-26 23:24:30.521797 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:24:30.785414 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-26 23:24:30.786933 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-03-26 23:24:33.505394 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-26 23:24:33.575295 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-26 23:24:33.591239 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-26 23:24:33.59261 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.which.1bb37c4982884d/results/test_pe.raw_variants.RData
2025-03-26 23:24:33.594288 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.wrap.callVariants.which.1bb37c4982884d/results/test_pe.filtered_variants.RData
2025-03-26 23:24:33.59553 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:24:33.732083 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-26 23:24:33.733446 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:24:33.913372 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-26 23:24:34.125816 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-03-26 23:25:27.656816 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/bkrtzdqf/merged/results/bla.coverage.RData
2025-03-26 23:25:27.659814 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpZpALYv/bkrtzdqf/merged/results/bla.coverage.bw
2025-03-26 23:25:27.740158 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/bkrtzdqf/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-03-26 23:25:28.849024 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/qlbtdruv/merged/results/bla.coverage.RData
2025-03-26 23:25:28.850858 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpZpALYv/qlbtdruv/merged/results/bla.coverage.bw
2025-03-26 23:25:28.862168 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/qlbtdruv/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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/RtmpZpALYv/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-03-26 23:25:30.039413 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-26 23:25:30.040477 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpZpALYv/test.detectRRNA.1bb37c59b3acae/bams/rRNA_contam/input1.fastq
2025-03-26 23:25:30.043529 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/RtmpZpALYv/test.detectRRNA.1bb37c59b3acae/bams/rRNA_contam/test_se /tmp/RtmpZpALYv/test.detectRRNA.1bb37c59b3acae/bams/rRNA_contam/input1.fastq 2>&1
2025-03-26 23:25:30.212511 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-26 23:25:30.213505 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:25:30.364007 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-26 23:25:30.36598 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpZpALYv/test.detectRRNA.paired_end.1bb37c24fc4c35/bams/rRNA_contam/input1.fastq
2025-03-26 23:25:30.367461 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpZpALYv/test.detectRRNA.paired_end.1bb37c24fc4c35/bams/rRNA_contam/input2.fastq
2025-03-26 23:25:30.369587 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/RtmpZpALYv/test.detectRRNA.paired_end.1bb37c24fc4c35/bams/rRNA_contam/test_pe /tmp/RtmpZpALYv/test.detectRRNA.paired_end.1bb37c24fc4c35/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpZpALYv/test.detectRRNA.paired_end.1bb37c24fc4c35/bams/rRNA_contam/input2.fastq 2>&1
2025-03-26 23:25:30.605416 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-26 23:25:30.606407 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-03-26 23:25:30.625142 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/RtmpZpALYv/test_get_rRNA_idspvnlaosu/test_pe /tmp/RtmpZpALYv/test_get_rRNA_idspvnlaosu/1.fastq -a paired /tmp/RtmpZpALYv/test_get_rRNA_idspvnlaosu/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-03-26 23:25:30.870635 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/RtmpZpALYv/test_get_rRNAIds_randompsjkimga/test_pe /tmp/RtmpZpALYv/test_get_rRNAIds_randompsjkimga/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-03-26 23:25:31.125359 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-26 23:25:31.1269 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-03-26 23:25:31.127809 INFO::filterQuality.R/filterByLength: done
2025-03-26 23:25:31.174204 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-26 23:25:31.175161 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-03-26 23:25:31.176019 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-03-26 23:25:31.225648 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-26 23:25:31.234347 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-26 23:25:31.235409 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-26 23:25:31.239766 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-26 23:25:31.240753 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-26 23:25:31.245056 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-26 23:25:31.245987 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-26 23:25:31.250269 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



Executing test function test.realignIndelsGATK.parallel  ... Timing stopped at: 0 0 0.001
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/RtmpZpALYv/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-03-26 23:25:31.519341 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-03-26 23:25:31.521672 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/RtmpZpALYv/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-03-26 23:25:31.703372 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-03-26 23:25:31.772932 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-26 23:25:31.775627 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-03-26 23:25:31.777786 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/RtmpZpALYv/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-03-26 23:25:31.972054 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/RtmpZpALYv/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-03-26 23:25:32.116709 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/RtmpZpALYv/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-03-26 23:25:32.255475 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-03-26 23:25:32.301891 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-26 23:25:32.304344 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-03-26 23:25:32.306561 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/RtmpZpALYv/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-03-26 23:25:32.492986 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-03-26 23:25:32.536754 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-26 23:25:32.539251 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-03-26 23:25:32.541489 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/RtmpZpALYv/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/RtmpZpALYv/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-03-26 23:25:33.269991 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-26 23:25:33.276189 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-03-26 23:25:33.279706 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-03-26 23:25:33.282164 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:25:36.934397 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:25:36.935889 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000001/logs/progress.log
2025-03-26 23:25:39.506808 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-26 23:25:39.508236 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000002/logs/progress.log
2025-03-26 23:25:42.084312 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-03-26 23:25:42.086534 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000003/logs/progress.log
2025-03-26 23:25:44.704432 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-03-26 23:25:44.7449 DEBUG::tools.R/processChunks: done
2025-03-26 23:25:44.747545 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:25:44.749128 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.adapter_contaminated_1.RData
2025-03-26 23:25:44.751084 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-26 23:25:44.752483 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.adapter_contaminated_2.RData
2025-03-26 23:25:44.76037 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-03-26 23:25:44.762162 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.summary_preprocess.tab
2025-03-26 23:25:44.764513 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/bams/processed.aligner_input_1.fastq ...
2025-03-26 23:25:44.768308 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/bams/processed.aligner_input_2.fastq ...
2025-03-26 23:25:44.771279 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/reports/shortReadReport_1 ...
2025-03-26 23:25:46.080741 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/reports/shortReadReport_2 ...
2025-03-26 23:25:47.141547 INFO::preprocessReads.R/preprocessReads: done
2025-03-26 23:25:47.242946 INFO::alignReads.R/alignReads: starting alignment...
2025-03-26 23:25:47.247331 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:25:50.570815 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:25:50.572571 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000001/logs/progress.log
2025-03-26 23:25:53.188361 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-03-26 23:25:53.190042 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/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-03-26 23:25:55.805979 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-26 23:25:55.807753 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/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-03-26 23:25:58.466516 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-03-26 23:25:58.469501 DEBUG::tools.R/processChunks: done
2025-03-26 23:25:58.471331 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-03-26 23:25:58.694 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-26 23:25:58.702198 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.summary_alignment.tab
2025-03-26 23:25:58.709639 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.summary_analyzed_bamstats.tab
2025-03-26 23:25:58.712284 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-26 23:25:58.941212 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.summary_target_lengths.tab
2025-03-26 23:25:58.988575 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-26 23:25:58.989627 INFO::alignReads.R/alignReads: done
2025-03-26 23:25:59.089471 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-03-26 23:25:59.109217 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:26:02.085332 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:26:02.087255 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000001/logs/progress.log
2025-03-26 23:26:04.547194 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-03-26 23:26:04.54864 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000002/logs/progress.log
2025-03-26 23:26:07.100564 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-03-26 23:26:07.102822 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000003/logs/progress.log
2025-03-26 23:26:10.317272 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.054 minutes
2025-03-26 23:26:10.326563 DEBUG::tools.R/processChunks: done
2025-03-26 23:26:10.337106 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-26 23:26:10.385745 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.counts_exon.tab
2025-03-26 23:26:10.418262 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.counts_exon_disjoint.tab
2025-03-26 23:26:10.431695 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.counts_gene.tab
2025-03-26 23:26:10.44174 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.counts_gene_coding.tab
2025-03-26 23:26:10.451948 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.counts_gene_exonic.tab
2025-03-26 23:26:10.462562 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.counts_intergenic.tab
2025-03-26 23:26:10.480268 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.counts_intron.tab
2025-03-26 23:26:10.484843 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-26 23:26:10.495136 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.summary_counts.tab
2025-03-26 23:26:10.498439 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-26 23:26:11.16228 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-26 23:26:11.164249 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-03-26 23:26:11.595675 INFO::coverage.R/calculateCoverage: starting...
2025-03-26 23:26:11.606752 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:26:19.290912 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:26:19.29429 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000001/logs/progress.log
2025-03-26 23:26:21.707759 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2025-03-26 23:26:21.715503 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000002/logs/progress.log
2025-03-26 23:26:24.237654 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2025-03-26 23:26:24.244131 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/chunks/chunk_000003/logs/progress.log
2025-03-26 23:26:26.992744 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-03-26 23:26:27.012528 DEBUG::tools.R/processChunks: done
2025-03-26 23:26:31.308237 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.coverage.RData
2025-03-26 23:26:31.312628 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.coverage.bw
2025-03-26 23:26:31.342526 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.summary_coverage.tab
2025-03-26 23:26:31.346007 INFO::coverage.R/calculateCoverage: done
2025-03-26 23:26:31.350467 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-26 23:26:31.731229 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-26 23:26:36.080928 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-26 23:26:36.154192 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-26 23:26:36.171134 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-26 23:26:36.172625 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.raw_variants.RData
2025-03-26 23:26:36.174438 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.filtered_variants.RData
2025-03-26 23:26:36.175822 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-26 23:26:36.176889 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-26 23:26:36.671955 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-26 23:26:36.963907 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/results/test_pe.summary_variants.tab
2025-03-26 23:26:36.96959 INFO::analyzeVariants/analyzeVariants: done
2025-03-26 23:26:36.976924 INFO::Pipeline run successful.
2025-03-26 23:26:37.344501 INFO::mergeLanes.R/doMergeLanes: starting...
2025-03-26 23:26:37.35356 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:26:37.357904 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.adapter_contaminated_1.RData
2025-03-26 23:26:37.363356 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-26 23:26:37.366799 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.adapter_contaminated_2.RData
2025-03-26 23:26:37.389585 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-03-26 23:26:37.394197 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.summary_preprocess.tab
2025-03-26 23:26:37.398719 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-03-26 23:26:37.935426 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-26 23:26:37.950553 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.summary_alignment.tab
2025-03-26 23:26:37.967816 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.summary_analyzed_bamstats.tab
2025-03-26 23:26:37.972671 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-26 23:26:38.398131 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.summary_target_lengths.tab
2025-03-26 23:26:38.495684 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-26 23:26:38.594713 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-26 23:26:38.626673 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.counts_exon.tab
2025-03-26 23:26:38.642349 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.counts_exon_disjoint.tab
2025-03-26 23:26:38.652142 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.counts_gene.tab
2025-03-26 23:26:38.659063 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.counts_gene_coding.tab
2025-03-26 23:26:38.665934 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.counts_gene_exonic.tab
2025-03-26 23:26:38.6727 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.counts_intergenic.tab
2025-03-26 23:26:38.68747 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.counts_intron.tab
2025-03-26 23:26:38.690853 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-26 23:26:38.698812 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.summary_counts.tab
2025-03-26 23:26:38.701261 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-26 23:26:38.975153 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-26 23:26:42.082623 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.coverage.RData
2025-03-26 23:26:42.087464 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.coverage.bw
2025-03-26 23:26:42.105533 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.summary_coverage.tab
2025-03-26 23:26:42.219858 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-26 23:26:42.470105 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-26 23:26:47.891015 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-26 23:26:48.046962 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-26 23:26:48.082378 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-26 23:26:48.085328 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.raw_variants.RData
2025-03-26 23:26:48.08879 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.filtered_variants.RData
2025-03-26 23:26:48.091814 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-26 23:26:48.094113 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-26 23:26:48.565779 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-26 23:26:48.766881 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.mergeLanes.1bb37c4463d0e3/merged/results/merged.summary_variants.tab
2025-03-26 23:26:48.770571 INFO::analyzeVariants/analyzeVariants: done
2025-03-26 23:26:48.775105 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0 0.001 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/RtmpZpALYv/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-03-26 23:26:49.322542 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-26 23:26:49.348583 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-03-26 23:26:49.36963 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-03-26 23:26:49.373408 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:26:53.089415 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:26:53.091268 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/chunks/chunk_000001/logs/progress.log
2025-03-26 23:26:56.253648 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.053 minutes
2025-03-26 23:26:56.31692 DEBUG::tools.R/processChunks: done
2025-03-26 23:26:56.320676 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:26:56.323372 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/results/test_pe.adapter_contaminated_1.RData
2025-03-26 23:26:56.326309 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-26 23:26:56.328815 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/results/test_pe.adapter_contaminated_2.RData
2025-03-26 23:26:56.339216 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-03-26 23:26:56.342076 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/results/test_pe.summary_preprocess.tab
2025-03-26 23:26:56.345283 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/bams/processed.aligner_input_1.fastq ...
2025-03-26 23:26:56.351928 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/bams/processed.aligner_input_2.fastq ...
2025-03-26 23:26:56.358583 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/reports/shortReadReport_1 ...
2025-03-26 23:26:57.931843 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.preprocessReads.1bb37c3791d306/reports/shortReadReport_2 ...
2025-03-26 23:26:58.968067 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:26:59.249942 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-26 23:26:59.256773 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-03-26 23:26:59.261282 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-03-26 23:26:59.352578 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:27:03.327136 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:27:03.328859 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/chunks/chunk_000001/logs/progress.log
2025-03-26 23:27:06.034336 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-03-26 23:27:06.0361 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/chunks/chunk_000002/logs/progress.log
2025-03-26 23:27:08.691916 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-26 23:27:08.693443 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/chunks/chunk_000003/logs/progress.log
2025-03-26 23:27:11.284768 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-03-26 23:27:11.326802 DEBUG::tools.R/processChunks: done
2025-03-26 23:27:11.329427 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:27:11.33102 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/results/test_pe.adapter_contaminated_1.RData
2025-03-26 23:27:11.332959 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-26 23:27:11.33435 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/results/test_pe.adapter_contaminated_2.RData
2025-03-26 23:27:11.342126 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-03-26 23:27:11.343837 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/results/test_pe.summary_preprocess.tab
2025-03-26 23:27:11.34613 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/bams/processed.aligner_input_1.fastq ...
2025-03-26 23:27:11.350215 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/bams/processed.aligner_input_2.fastq ...
2025-03-26 23:27:11.354151 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/reports/shortReadReport_1 ...
2025-03-26 23:27:12.649742 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.preprocessReads.minichunks.1bb37c6c409270/reports/shortReadReport_2 ...
2025-03-26 23:27:13.718915 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpZpALYv/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-03-26 23:27:14.012949 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-26 23:27:14.03389 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-03-26 23:27:14.036563 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:27:17.225461 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:27:17.2269 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpZpALYv/test.preprocessReads_single_end.1bb37c36fe22d6/chunks/chunk_000001/logs/progress.log
2025-03-26 23:27:19.596206 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2025-03-26 23:27:19.630516 DEBUG::tools.R/processChunks: done
2025-03-26 23:27:19.632806 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:27:19.634381 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads_single_end.1bb37c36fe22d6/results/test_se.adapter_contaminated_1.RData
2025-03-26 23:27:19.640384 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-03-26 23:27:19.641984 INFO::io.R/saveWithID: saving file= /tmp/RtmpZpALYv/test.preprocessReads_single_end.1bb37c36fe22d6/results/test_se.summary_preprocess.tab
2025-03-26 23:27:19.643738 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpZpALYv/test.preprocessReads_single_end.1bb37c36fe22d6/bams/processed.aligner_input_1.fastq ...
2025-03-26 23:27:19.647292 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpZpALYv/test.preprocessReads_single_end.1bb37c36fe22d6/reports/shortReadReport_1 ...
2025-03-26 23:27:20.936692 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-03-26 23:27:21.572396 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-26 23:27:21.593552 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-03-26 23:27:21.612706 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-03-26 23:27:21.615714 DEBUG::tools.R/processChunks: starting...
2025-03-26 23:27:24.637609 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-26 23:27:24.639139 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-03-26 23:27:27.41829 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-03-26 23:27:27.457213 DEBUG::tools.R/processChunks: done
2025-03-26 23:27:27.459418 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-26 23:27:27.460885 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-03-26 23:27:27.462521 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-26 23:27:27.463769 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-03-26 23:27:27.469729 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-03-26 23:27:27.471454 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-03-26 23:27:27.47344 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-03-26 23:27:27.477448 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-03-26 23:27:27.481463 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-03-26 23:28:21.594845 DEBUG::tools.R/traceMem: wired.mem=15.760069 GiB
2025-03-26 23:29:21.661108 DEBUG::tools.R/traceMem: wired.mem=21.383426 GiB
2025-03-26 23:30:21.72649 DEBUG::tools.R/traceMem: wired.mem=23.958991 GiB
2025-03-26 23:31:21.791881 DEBUG::tools.R/traceMem: wired.mem=25.160774 GiB
2025-03-26 23:32:21.859772 DEBUG::tools.R/traceMem: wired.mem=26.716164 GiB
2025-03-26 23:33:21.927273 DEBUG::tools.R/traceMem: wired.mem=22.939521 GiB
2025-03-26 23:34:21.994044 DEBUG::tools.R/traceMem: wired.mem=32.147149 GiB
2025-03-26 23:35:22.061397 DEBUG::tools.R/traceMem: wired.mem=28.056457 GiB
2025-03-26 23:36:22.127163 DEBUG::tools.R/traceMem: wired.mem=32.996241 GiB
2025-03-26 23:37:22.192489 DEBUG::tools.R/traceMem: wired.mem=27.509133 GiB
2025-03-26 23:38:22.25874 DEBUG::tools.R/traceMem: wired.mem=27.290628 GiB
2025-03-26 23:39:22.325266 DEBUG::tools.R/traceMem: wired.mem=24.842875 GiB
2025-03-26 23:40:22.391025 DEBUG::tools.R/traceMem: wired.mem=18.610803 GiB
2025-03-26 23:41:22.45603 DEBUG::tools.R/traceMem: wired.mem=32.022335 GiB
2025-03-26 23:42:22.520814 DEBUG::tools.R/traceMem: wired.mem=28.041081 GiB
2025-03-26 23:43:22.585762 DEBUG::tools.R/traceMem: wired.mem=25.643651 GiB
2025-03-26 23:44:22.652756 DEBUG::tools.R/traceMem: wired.mem=29.505155 GiB
2025-03-26 23:45:22.717273 DEBUG::tools.R/traceMem: wired.mem=15.995761 GiB
2025-03-26 23:46:22.781571 DEBUG::tools.R/traceMem: wired.mem=18.200834 GiB
2025-03-26 23:47:22.847892 DEBUG::tools.R/traceMem: wired.mem=19.006673 GiB
2025-03-26 23:48:22.913618 DEBUG::tools.R/traceMem: wired.mem=22.712046 GiB
2025-03-26 23:49:22.98028 DEBUG::tools.R/traceMem: wired.mem=31.480959 GiB
2025-03-26 23:50:23.046558 DEBUG::tools.R/traceMem: wired.mem=24.510018 GiB
2025-03-26 23:51:23.112321 DEBUG::tools.R/traceMem: wired.mem=23.332516 GiB
2025-03-26 23:52:23.179459 DEBUG::tools.R/traceMem: wired.mem=33.413321 GiB
2025-03-26 23:53:23.246406 DEBUG::tools.R/traceMem: wired.mem=32.026153 GiB
2025-03-26 23:54:23.313689 DEBUG::tools.R/traceMem: wired.mem=35.880489 GiB
2025-03-26 23:55:23.379616 DEBUG::tools.R/traceMem: wired.mem=28.969005 GiB
2025-03-26 23:56:23.446759 DEBUG::tools.R/traceMem: wired.mem=27.072557 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