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-01-20 r87609) -- "Unsuffered Consequences"	4720
palomino7	Windows Server 2022 Datacenter	x64	R Under development (unstable) (2025-01-21 r87610 ucrt) -- "Unsuffered Consequences"	4482
lconway	macOS 12.7.1 Monterey	x86_64	R Under development (unstable) (2025-01-22 r87618) -- "Unsuffered Consequences"	4493
kjohnson3	macOS 13.7.1 Ventura	arm64	R Under development (unstable) (2025-01-20 r87609) -- "Unsuffered Consequences"	4446
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-02-14 22:59:17 -0500 (Fri, 14 Feb 2025)

EndedAt: 2025-02-14 23:39:18 -0500 (Fri, 14 Feb 2025)

EllapsedTime: 2400.7 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-01-20 r87609)
* 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-01-20 r87609) -- "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/RtmpPzBKli/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-02-14 23:04:49.595162 INFO::preprocessReads.R/preprocessReads: starting...
2025-02-14 23:04:49.602911 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-02-14 23:04:49.606569 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-02-14 23:04:49.608725 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:04:52.225272 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:04:52.226763 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/chunks/chunk_000001/logs/progress.log
2025-02-14 23:04:54.93859 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-02-14 23:04:54.94061 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/chunks/chunk_000002/logs/progress.log
2025-02-14 23:04:57.656217 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-02-14 23:04:57.658138 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/chunks/chunk_000003/logs/progress.log
2025-02-14 23:05:00.372386 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-02-14 23:05:00.406533 DEBUG::tools.R/processChunks: done
2025-02-14 23:05:00.410816 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:05:00.413314 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/results/test_pe.adapter_contaminated_1.RData
2025-02-14 23:05:00.416135 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-02-14 23:05:00.417832 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/results/test_pe.adapter_contaminated_2.RData
2025-02-14 23:05:00.427431 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-02-14 23:05:00.429685 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/results/test_pe.summary_preprocess.tab
2025-02-14 23:05:00.432857 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/bams/processed.aligner_input_1.fastq ...
2025-02-14 23:05:00.437684 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/bams/processed.aligner_input_2.fastq ...
2025-02-14 23:05:00.440942 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/reports/shortReadReport_1 ...
2025-02-14 23:05:01.884266 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/reports/shortReadReport_2 ...
2025-02-14 23:05:04.438741 INFO::preprocessReads.R/preprocessReads: done
2025-02-14 23:05:04.528387 INFO::alignReads.R/alignReads: starting alignment...
2025-02-14 23:05:04.533911 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:05:07.314234 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:05:07.315829 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/chunks/chunk_000001/logs/progress.log
2025-02-14 23:05:10.038775 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-02-14 23:05:10.041923 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/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-02-14 23:05:12.72208 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-02-14 23:05:12.724572 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/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-02-14 23:05:15.367508 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-02-14 23:05:15.370042 DEBUG::tools.R/processChunks: done
2025-02-14 23:05:15.371468 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-02-14 23:05:15.58922 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-02-14 23:05:15.597805 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/results/test_pe.summary_alignment.tab
2025-02-14 23:05:15.605135 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/results/test_pe.summary_analyzed_bamstats.tab
2025-02-14 23:05:15.606847 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-02-14 23:05:15.853177 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.a35f846cc0065/results/test_pe.summary_target_lengths.tab
2025-02-14 23:05:15.901341 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-02-14 23:05:15.902571 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:05:16.182422 INFO::preprocessReads.R/preprocessReads: starting...
2025-02-14 23:05:16.185857 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-02-14 23:05:16.24903 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-02-14 23:05:16.253798 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-02-14 23:05:16.257056 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-02-14 23:05:16.259323 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:05:18.996396 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:05:19.009273 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/chunks/chunk_000001/logs/progress.log
2025-02-14 23:05:21.666194 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-02-14 23:05:21.667509 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/chunks/chunk_000002/logs/progress.log
2025-02-14 23:05:24.336065 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-02-14 23:05:24.337483 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/chunks/chunk_000003/logs/progress.log
2025-02-14 23:05:27.097178 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-02-14 23:05:27.099265 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/chunks/chunk_000004/logs/progress.log
2025-02-14 23:05:29.752533 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2025-02-14 23:05:29.791619 DEBUG::tools.R/processChunks: done
2025-02-14 23:05:29.796231 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:05:29.799685 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/results/test_pe.adapter_contaminated_1.RData
2025-02-14 23:05:29.803944 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-02-14 23:05:29.806514 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/results/test_pe.adapter_contaminated_2.RData
2025-02-14 23:05:29.820822 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-02-14 23:05:29.823932 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/results/test_pe.summary_preprocess.tab
2025-02-14 23:05:29.828789 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/bams/processed.aligner_input_1.fastq ...
2025-02-14 23:05:29.834865 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/bams/processed.aligner_input_2.fastq ...
2025-02-14 23:05:29.83995 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/reports/shortReadReport_1 ...
2025-02-14 23:05:31.151863 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.alignReads.sparsechunks.a35f83b2cd2ab/reports/shortReadReport_2 ...
2025-02-14 23:05:33.596009 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:05:33.77974 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-02-14 23:05:33.783719 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/RtmpPzBKli/test.alignReadsOneSingleEnd.a35f8711116f9/bams/test.alignReads /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-02-14 23:05:33.976306 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-02-14 23:05:34.072586 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReadsOneSingleEnd.a35f8711116f9/results/test.alignReads.summary_alignment.tab
2025-02-14 23:05:34.123429 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.alignReadsOneSingleEnd.a35f8711116f9/results/test.alignReads.summary_analyzed_bamstats.tab
2025-02-14 23:05:34.12485 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/RtmpPzBKli/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-02-14 23:05:34.418102 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.genotype.a35f860f3199d/results/test_pe.coverage.RData
2025-02-14 23:05:34.419904 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpPzBKli/test.genotype.a35f860f3199d/results/test_pe.coverage.bw
2025-02-14 23:05:34.527523 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.genotype.a35f860f3199d/results/test_pe.summary_coverage.tab
2025-02-14 23:05:34.529128 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-02-14 23:05:44.815197 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-02-14 23:05:44.916785 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-02-14 23:05:44.938902 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-02-14 23:05:44.940977 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.genotype.a35f860f3199d/results/test_pe.raw_variants.RData
2025-02-14 23:05:44.944024 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.genotype.a35f860f3199d/results/test_pe.filtered_variants.RData
2025-02-14 23:05:44.945908 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-02-14 23:05:44.947551 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-02-14 23:05:45.435709 INFO::analyzeVariants.R/writeVCF: ...done
2025-02-14 23:05:45.43709 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-02-14 23:06:47.421821 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-02-14 23:06:47.855738 INFO::analyzeVariants.R/writeVCF: ...done
2025-02-14 23:06:47.856761 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/RtmpPzBKli/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-02-14 23:06:48.339809 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-02-14 23:06:58.884555 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-02-14 23:06:58.959131 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-02-14 23:06:58.975375 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-02-14 23:06:58.976744 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.a35f83467fc7/results/test_pe.raw_variants.RData
2025-02-14 23:06:58.97916 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.a35f83467fc7/results/test_pe.filtered_variants.RData
2025-02-14 23:06:58.98052 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:06:59.114464 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-02-14 23:07:09.01247 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-02-14 23:07:09.072379 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-02-14 23:07:09.089429 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-02-14 23:07:09.090909 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.filters.a35f8657f6203/results/test_pe.raw_variants.RData
2025-02-14 23:07:09.09334 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.filters.a35f8657f6203/results/test_pe.filtered_variants.RData
2025-02-14 23:07:09.094633 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-02-14 23:07:09.096131 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-02-14 23:07:19.14835 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-02-14 23:07:19.185915 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-02-14 23:07:19.202245 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-02-14 23:07:19.203645 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.filters.a35f8657f6203/results/test_pe.raw_variants.RData
2025-02-14 23:07:19.20614 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.filters.a35f8657f6203/results/test_pe.filtered_variants.RData
2025-02-14 23:07:19.208133 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:07:19.455823 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-02-14 23:07:19.457381 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-02-14 23:07:22.003054 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-02-14 23:07:22.075768 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-02-14 23:07:22.092283 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-02-14 23:07:22.093676 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.which.a35f859622336/results/test_pe.raw_variants.RData
2025-02-14 23:07:22.095242 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.wrap.callVariants.which.a35f859622336/results/test_pe.filtered_variants.RData
2025-02-14 23:07:22.096493 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:07:22.243302 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-02-14 23:07:22.244652 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:07:22.41503 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-02-14 23:07:22.622929 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-02-14 23:08:13.338051 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/ewocytfi/merged/results/bla.coverage.RData
2025-02-14 23:08:13.341083 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpPzBKli/ewocytfi/merged/results/bla.coverage.bw
2025-02-14 23:08:13.420268 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/ewocytfi/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-02-14 23:08:14.617276 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/yuhvfwxg/merged/results/bla.coverage.RData
2025-02-14 23:08:14.618951 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpPzBKli/yuhvfwxg/merged/results/bla.coverage.bw
2025-02-14 23:08:14.630162 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/yuhvfwxg/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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/RtmpPzBKli/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-02-14 23:08:15.911752 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-02-14 23:08:15.912937 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpPzBKli/test.detectRRNA.a35f812fdd886/bams/rRNA_contam/input1.fastq
2025-02-14 23:08:15.916163 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/RtmpPzBKli/test.detectRRNA.a35f812fdd886/bams/rRNA_contam/test_se /tmp/RtmpPzBKli/test.detectRRNA.a35f812fdd886/bams/rRNA_contam/input1.fastq 2>&1
2025-02-14 23:08:16.092568 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-02-14 23:08:16.093655 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:08:16.258735 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-02-14 23:08:16.259855 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpPzBKli/test.detectRRNA.paired_end.a35f8730b20c2/bams/rRNA_contam/input1.fastq
2025-02-14 23:08:16.26149 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpPzBKli/test.detectRRNA.paired_end.a35f8730b20c2/bams/rRNA_contam/input2.fastq
2025-02-14 23:08:16.263783 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/RtmpPzBKli/test.detectRRNA.paired_end.a35f8730b20c2/bams/rRNA_contam/test_pe /tmp/RtmpPzBKli/test.detectRRNA.paired_end.a35f8730b20c2/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpPzBKli/test.detectRRNA.paired_end.a35f8730b20c2/bams/rRNA_contam/input2.fastq 2>&1
2025-02-14 23:08:16.503929 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-02-14 23:08:16.504958 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-02-14 23:08:16.523727 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/RtmpPzBKli/test_get_rRNA_idswyrhgdkc/test_pe /tmp/RtmpPzBKli/test_get_rRNA_idswyrhgdkc/1.fastq -a paired /tmp/RtmpPzBKli/test_get_rRNA_idswyrhgdkc/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-02-14 23:08:16.768778 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/RtmpPzBKli/test_get_rRNAIds_randomxbspafoy/test_pe /tmp/RtmpPzBKli/test_get_rRNAIds_randomxbspafoy/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-02-14 23:08:17.024431 INFO::filterQuality.R/filterQuality: filterByLength...
2025-02-14 23:08:17.026044 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-02-14 23:08:17.02709 INFO::filterQuality.R/filterByLength: done
2025-02-14 23:08:17.075984 INFO::filterQuality.R/filterQuality: filterByLength...
2025-02-14 23:08:17.076932 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-02-14 23:08:17.077757 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-02-14 23:08:17.127541 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-02-14 23:08:17.136662 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-02-14 23:08:17.137818 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-02-14 23:08:17.142349 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-02-14 23:08:17.143361 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-02-14 23:08:17.147795 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-02-14 23:08:17.148753 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-02-14 23:08:17.153126 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:08:17.458126 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-02-14 23:08:17.460524 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/RtmpPzBKli/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-02-14 23:08:17.661726 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-02-14 23:08:17.786366 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-02-14 23:08:17.78932 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-02-14 23:08:17.791676 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/RtmpPzBKli/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-02-14 23:08:19.166873 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/RtmpPzBKli/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-02-14 23:08:19.303812 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/RtmpPzBKli/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-02-14 23:08:19.462904 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-02-14 23:08:19.532147 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-02-14 23:08:19.53472 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-02-14 23:08:19.536997 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/RtmpPzBKli/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-02-14 23:08:19.740203 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-02-14 23:08:19.785079 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-02-14 23:08:19.78767 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-02-14 23:08:19.789979 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/RtmpPzBKli/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/RtmpPzBKli/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-02-14 23:08:20.533402 INFO::preprocessReads.R/preprocessReads: starting...
2025-02-14 23:08:20.538857 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-02-14 23:08:20.542021 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-02-14 23:08:20.544113 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:08:23.376807 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:08:23.378337 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000001/logs/progress.log
2025-02-14 23:08:25.954145 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-02-14 23:08:25.955672 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000002/logs/progress.log
2025-02-14 23:08:28.540029 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-02-14 23:08:28.541687 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000003/logs/progress.log
2025-02-14 23:08:31.103512 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-02-14 23:08:31.150155 DEBUG::tools.R/processChunks: done
2025-02-14 23:08:31.153681 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:08:31.155637 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.adapter_contaminated_1.RData
2025-02-14 23:08:31.157887 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-02-14 23:08:31.159541 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.adapter_contaminated_2.RData
2025-02-14 23:08:31.168272 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-02-14 23:08:31.170154 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.summary_preprocess.tab
2025-02-14 23:08:31.172651 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/bams/processed.aligner_input_1.fastq ...
2025-02-14 23:08:31.176873 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/bams/processed.aligner_input_2.fastq ...
2025-02-14 23:08:31.180083 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/reports/shortReadReport_1 ...
2025-02-14 23:08:32.461948 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/reports/shortReadReport_2 ...
2025-02-14 23:08:33.504782 INFO::preprocessReads.R/preprocessReads: done
2025-02-14 23:08:33.592021 INFO::alignReads.R/alignReads: starting alignment...
2025-02-14 23:08:33.596614 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:08:36.35728 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:08:36.358984 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000001/logs/progress.log
2025-02-14 23:08:38.954304 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-02-14 23:08:38.956082 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/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-02-14 23:08:41.597276 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-02-14 23:08:41.598976 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/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-02-14 23:08:44.205457 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-02-14 23:08:44.207993 DEBUG::tools.R/processChunks: done
2025-02-14 23:08:44.209549 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-02-14 23:08:44.401292 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-02-14 23:08:44.408869 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.summary_alignment.tab
2025-02-14 23:08:44.415311 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.summary_analyzed_bamstats.tab
2025-02-14 23:08:44.417052 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-02-14 23:08:44.634565 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.summary_target_lengths.tab
2025-02-14 23:08:44.680115 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-02-14 23:08:44.681158 INFO::alignReads.R/alignReads: done
2025-02-14 23:08:44.78979 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-02-14 23:08:44.810356 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:08:47.770089 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:08:47.771759 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000001/logs/progress.log
2025-02-14 23:08:50.234873 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-02-14 23:08:50.236785 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000002/logs/progress.log
2025-02-14 23:08:52.678512 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2025-02-14 23:08:52.680672 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000003/logs/progress.log
2025-02-14 23:08:55.14772 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2025-02-14 23:08:55.150193 DEBUG::tools.R/processChunks: done
2025-02-14 23:08:55.151902 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-02-14 23:08:55.166529 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.counts_exon.tab
2025-02-14 23:08:55.178125 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.counts_exon_disjoint.tab
2025-02-14 23:08:55.185201 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.counts_gene.tab
2025-02-14 23:08:55.190602 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.counts_gene_coding.tab
2025-02-14 23:08:55.19559 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.counts_gene_exonic.tab
2025-02-14 23:08:55.200881 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.counts_intergenic.tab
2025-02-14 23:08:55.210286 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.counts_intron.tab
2025-02-14 23:08:55.213113 INFO::countGenomicFeatures.R/mergeCounts: done
2025-02-14 23:08:55.21876 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.summary_counts.tab
2025-02-14 23:08:55.220496 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-02-14 23:08:55.527085 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-02-14 23:08:55.528105 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-02-14 23:08:55.624842 INFO::coverage.R/calculateCoverage: starting...
2025-02-14 23:08:55.629457 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:08:58.609885 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:08:58.611523 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000001/logs/progress.log
2025-02-14 23:09:00.772399 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2025-02-14 23:09:00.774051 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000002/logs/progress.log
2025-02-14 23:09:02.952616 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2025-02-14 23:09:02.95435 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/chunks/chunk_000003/logs/progress.log
2025-02-14 23:09:05.157378 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2025-02-14 23:09:05.159948 DEBUG::tools.R/processChunks: done
2025-02-14 23:09:10.381223 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.coverage.RData
2025-02-14 23:09:10.392673 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.coverage.bw
2025-02-14 23:09:10.459699 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.summary_coverage.tab
2025-02-14 23:09:10.467161 INFO::coverage.R/calculateCoverage: done
2025-02-14 23:09:10.477963 INFO::analyzeVariants/analyzeVariants: starting ...
2025-02-14 23:09:10.902442 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-02-14 23:09:17.713748 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-02-14 23:09:17.981262 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-02-14 23:09:18.016536 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-02-14 23:09:18.019097 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.raw_variants.RData
2025-02-14 23:09:18.022566 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.filtered_variants.RData
2025-02-14 23:09:18.024969 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-02-14 23:09:18.02683 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-02-14 23:09:18.502265 INFO::analyzeVariants.R/writeVCF: ...done
2025-02-14 23:09:18.75071 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/results/test_pe.summary_variants.tab
2025-02-14 23:09:18.754895 INFO::analyzeVariants/analyzeVariants: done
2025-02-14 23:09:18.765452 INFO::Pipeline run successful.
2025-02-14 23:09:19.327299 INFO::mergeLanes.R/doMergeLanes: starting...
2025-02-14 23:09:19.3544 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:09:19.363887 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.adapter_contaminated_1.RData
2025-02-14 23:09:19.370146 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-02-14 23:09:19.374529 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.adapter_contaminated_2.RData
2025-02-14 23:09:19.401071 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-02-14 23:09:19.406827 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.summary_preprocess.tab
2025-02-14 23:09:19.412056 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-02-14 23:09:20.132848 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-02-14 23:09:20.16266 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.summary_alignment.tab
2025-02-14 23:09:20.198604 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.summary_analyzed_bamstats.tab
2025-02-14 23:09:20.209401 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-02-14 23:09:20.999575 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.summary_target_lengths.tab
2025-02-14 23:09:21.150193 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-02-14 23:09:21.290221 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-02-14 23:09:21.374832 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.counts_exon.tab
2025-02-14 23:09:21.40074 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.counts_exon_disjoint.tab
2025-02-14 23:09:21.416242 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.counts_gene.tab
2025-02-14 23:09:21.428093 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.counts_gene_coding.tab
2025-02-14 23:09:21.439892 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.counts_gene_exonic.tab
2025-02-14 23:09:21.451559 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.counts_intergenic.tab
2025-02-14 23:09:21.476844 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.counts_intron.tab
2025-02-14 23:09:21.48221 INFO::countGenomicFeatures.R/mergeCounts: done
2025-02-14 23:09:21.494156 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.summary_counts.tab
2025-02-14 23:09:21.497719 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-02-14 23:09:22.002151 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-02-14 23:09:26.989907 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.coverage.RData
2025-02-14 23:09:26.995943 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.coverage.bw
2025-02-14 23:09:27.027871 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.summary_coverage.tab
2025-02-14 23:09:27.294121 INFO::analyzeVariants/analyzeVariants: starting ...
2025-02-14 23:09:27.61429 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-02-14 23:09:32.92834 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-02-14 23:09:33.011447 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-02-14 23:09:33.029807 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-02-14 23:09:33.031435 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.raw_variants.RData
2025-02-14 23:09:33.033381 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.filtered_variants.RData
2025-02-14 23:09:33.034934 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-02-14 23:09:33.036125 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-02-14 23:09:33.269654 INFO::analyzeVariants.R/writeVCF: ...done
2025-02-14 23:09:33.380341 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.mergeLanes.a35f8789caf83/merged/results/merged.summary_variants.tab
2025-02-14 23:09:33.382674 INFO::analyzeVariants/analyzeVariants: done
2025-02-14 23:09:33.386067 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0.001 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.001
Error in DEACTIVATED("Skipped markDuplicates() test") : 
  Skipped markDuplicates() test
 done successfully.



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:09:33.694521 INFO::preprocessReads.R/preprocessReads: starting...
2025-02-14 23:09:33.713551 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-02-14 23:09:33.729322 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-02-14 23:09:33.731701 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:09:41.478469 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:09:41.481902 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/chunks/chunk_000001/logs/progress.log
2025-02-14 23:09:44.656451 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.053 minutes
2025-02-14 23:09:44.761935 DEBUG::tools.R/processChunks: done
2025-02-14 23:09:44.766808 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:09:44.770107 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/results/test_pe.adapter_contaminated_1.RData
2025-02-14 23:09:44.773794 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-02-14 23:09:44.777067 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/results/test_pe.adapter_contaminated_2.RData
2025-02-14 23:09:44.792081 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-02-14 23:09:44.796626 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/results/test_pe.summary_preprocess.tab
2025-02-14 23:09:44.801375 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/bams/processed.aligner_input_1.fastq ...
2025-02-14 23:09:44.809874 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/bams/processed.aligner_input_2.fastq ...
2025-02-14 23:09:44.817846 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/reports/shortReadReport_1 ...
2025-02-14 23:09:47.345981 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.preprocessReads.a35f85cacd1c3/reports/shortReadReport_2 ...
2025-02-14 23:09:48.97491 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:09:49.491995 INFO::preprocessReads.R/preprocessReads: starting...
2025-02-14 23:09:49.499259 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-02-14 23:09:49.503666 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-02-14 23:09:49.506773 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:09:53.299785 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:09:53.301816 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/chunks/chunk_000001/logs/progress.log
2025-02-14 23:09:55.872276 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-02-14 23:09:55.87446 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/chunks/chunk_000002/logs/progress.log
2025-02-14 23:09:58.440949 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-02-14 23:09:58.442515 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/chunks/chunk_000003/logs/progress.log
2025-02-14 23:10:01.379309 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2025-02-14 23:10:01.417792 DEBUG::tools.R/processChunks: done
2025-02-14 23:10:01.421094 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:10:01.42292 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/results/test_pe.adapter_contaminated_1.RData
2025-02-14 23:10:01.425158 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-02-14 23:10:01.426837 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/results/test_pe.adapter_contaminated_2.RData
2025-02-14 23:10:01.43545 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-02-14 23:10:01.437337 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/results/test_pe.summary_preprocess.tab
2025-02-14 23:10:01.439947 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/bams/processed.aligner_input_1.fastq ...
2025-02-14 23:10:01.444089 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/bams/processed.aligner_input_2.fastq ...
2025-02-14 23:10:01.447613 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/reports/shortReadReport_1 ...
2025-02-14 23:10:02.850181 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.preprocessReads.minichunks.a35f861d0938f/reports/shortReadReport_2 ...
2025-02-14 23:10:04.051197 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpPzBKli/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-02-14 23:10:04.3206 INFO::preprocessReads.R/preprocessReads: starting...
2025-02-14 23:10:04.339581 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-02-14 23:10:04.34208 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:10:07.193359 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:10:07.194874 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpPzBKli/test.preprocessReads_single_end.a35f82930ad4f/chunks/chunk_000001/logs/progress.log
2025-02-14 23:10:09.567811 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2025-02-14 23:10:09.577504 DEBUG::tools.R/processChunks: done
2025-02-14 23:10:09.579818 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:10:09.581371 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads_single_end.a35f82930ad4f/results/test_se.adapter_contaminated_1.RData
2025-02-14 23:10:09.587814 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-02-14 23:10:09.589537 INFO::io.R/saveWithID: saving file= /tmp/RtmpPzBKli/test.preprocessReads_single_end.a35f82930ad4f/results/test_se.summary_preprocess.tab
2025-02-14 23:10:09.591454 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpPzBKli/test.preprocessReads_single_end.a35f82930ad4f/bams/processed.aligner_input_1.fastq ...
2025-02-14 23:10:09.595471 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpPzBKli/test.preprocessReads_single_end.a35f82930ad4f/reports/shortReadReport_1 ...
2025-02-14 23:10:10.862042 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-02-14 23:10:11.514077 INFO::preprocessReads.R/preprocessReads: starting...
2025-02-14 23:10:11.532292 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-02-14 23:10:11.548808 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-02-14 23:10:11.551394 DEBUG::tools.R/processChunks: starting...
2025-02-14 23:10:14.701261 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-02-14 23:10:14.702895 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-02-14 23:10:17.464784 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-02-14 23:10:17.508988 DEBUG::tools.R/processChunks: done
2025-02-14 23:10:17.511461 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-02-14 23:10:17.513154 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-02-14 23:10:17.515072 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-02-14 23:10:17.516573 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-02-14 23:10:17.524118 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-02-14 23:10:17.526226 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-02-14 23:10:17.528366 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-02-14 23:10:17.53314 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-02-14 23:10:17.537453 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-02-14 23:11:11.541094 DEBUG::tools.R/traceMem: wired.mem=23.575785 GiB
2025-02-14 23:12:11.607838 DEBUG::tools.R/traceMem: wired.mem=23.242379 GiB
2025-02-14 23:13:11.674021 DEBUG::tools.R/traceMem: wired.mem=20.141511 GiB
2025-02-14 23:14:11.739582 DEBUG::tools.R/traceMem: wired.mem=26.142151 GiB
2025-02-14 23:15:11.804806 DEBUG::tools.R/traceMem: wired.mem=28.017529 GiB
2025-02-14 23:16:11.871464 DEBUG::tools.R/traceMem: wired.mem=27.867763 GiB
2025-02-14 23:17:11.938178 DEBUG::tools.R/traceMem: wired.mem=40.113172 GiB
2025-02-14 23:18:12.003983 DEBUG::tools.R/traceMem: wired.mem=28.259914 GiB
2025-02-14 23:19:12.069278 DEBUG::tools.R/traceMem: wired.mem=27.889775 GiB
2025-02-14 23:20:12.134795 DEBUG::tools.R/traceMem: wired.mem=26.410258 GiB
2025-02-14 23:21:12.200312 DEBUG::tools.R/traceMem: wired.mem=27.058565 GiB
2025-02-14 23:22:12.265619 DEBUG::tools.R/traceMem: wired.mem=26.139070 GiB
2025-02-14 23:23:12.331844 DEBUG::tools.R/traceMem: wired.mem=21.179077 GiB
2025-02-14 23:24:12.397491 DEBUG::tools.R/traceMem: wired.mem=30.193414 GiB
2025-02-14 23:25:12.404963 DEBUG::tools.R/traceMem: wired.mem=20.454486 GiB
2025-02-14 23:26:12.423558 DEBUG::tools.R/traceMem: wired.mem=24.876249 GiB
2025-02-14 23:27:12.488164 DEBUG::tools.R/traceMem: wired.mem=20.444238 GiB
2025-02-14 23:28:12.553416 DEBUG::tools.R/traceMem: wired.mem=21.717504 GiB
2025-02-14 23:29:12.618133 DEBUG::tools.R/traceMem: wired.mem=22.681883 GiB
2025-02-14 23:30:12.68435 DEBUG::tools.R/traceMem: wired.mem=28.494041 GiB
2025-02-14 23:31:12.749656 DEBUG::tools.R/traceMem: wired.mem=30.460867 GiB
2025-02-14 23:32:12.815359 DEBUG::tools.R/traceMem: wired.mem=26.452824 GiB
2025-02-14 23:33:12.881675 DEBUG::tools.R/traceMem: wired.mem=32.908349 GiB
2025-02-14 23:34:12.946688 DEBUG::tools.R/traceMem: wired.mem=29.424562 GiB
2025-02-14 23:35:13.014416 DEBUG::tools.R/traceMem: wired.mem=31.313310 GiB
2025-02-14 23:36:13.079888 DEBUG::tools.R/traceMem: wired.mem=35.994685 GiB
2025-02-14 23:37:13.14541 DEBUG::tools.R/traceMem: wired.mem=34.610188 GiB
2025-02-14 23:38:13.212349 DEBUG::tools.R/traceMem: wired.mem=31.611212 GiB
2025-02-14 23:39:13.277996 DEBUG::tools.R/traceMem: wired.mem=33.884058 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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