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) (2024-10-21 r87258) -- "Unsuffered Consequences"	4767
palomino7	Windows Server 2022 Datacenter	x64	R Under development (unstable) (2024-10-26 r87273 ucrt) -- "Unsuffered Consequences"	4487
lconway	macOS 12.7.1 Monterey	x86_64	R Under development (unstable) (2024-11-20 r87352) -- "Unsuffered Consequences"	4450
kjohnson3	macOS 13.7.1 Ventura	arm64	R Under development (unstable) (2024-11-20 r87352) -- "Unsuffered Consequences"	4405
kunpeng2	Linux (openEuler 22.03 LTS-SP1)	aarch64	R Under development (unstable) (2024-11-24 r87369) -- "Unsuffered Consequences"	4398
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-01-13 22:54:19 -0500 (Mon, 13 Jan 2025)

EndedAt: 2025-01-13 23:34:20 -0500 (Mon, 13 Jan 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) (2024-10-21 r87258)
* using platform: x86_64-pc-linux-gnu
* R was compiled by
    gcc (Ubuntu 13.2.0-23ubuntu4) 13.2.0
    GNU Fortran (Ubuntu 13.2.0-23ubuntu4) 13.2.0
* running under: Ubuntu 24.04.1 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’ ...
** 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) (2024-10-21 r87258) -- "Unsuffered Consequences"
Copyright (C) 2024 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu

R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.

R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.

Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.

> library("HTSeqGenie")
Loading required package: gmapR
Loading required package: GenomeInfoDb
Loading required package: BiocGenerics
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/RtmpOVZ2We/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-01-13 22:59:51.726313 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-13 22:59:51.734795 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-01-13 22:59:51.738744 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-01-13 22:59:51.740915 DEBUG::tools.R/processChunks: starting...
2025-01-13 22:59:54.95555 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 22:59:54.957054 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/chunks/chunk_000001/logs/progress.log
2025-01-13 22:59:57.735845 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-01-13 22:59:57.737415 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/chunks/chunk_000002/logs/progress.log
2025-01-13 23:00:00.499351 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-01-13 23:00:00.501495 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/chunks/chunk_000003/logs/progress.log
2025-01-13 23:00:03.347749 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2025-01-13 23:00:03.385788 DEBUG::tools.R/processChunks: done
2025-01-13 23:00:03.390738 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:00:03.393366 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/results/test_pe.adapter_contaminated_1.RData
2025-01-13 23:00:03.396229 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-13 23:00:03.397931 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/results/test_pe.adapter_contaminated_2.RData
2025-01-13 23:00:03.407833 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-01-13 23:00:03.410249 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/results/test_pe.summary_preprocess.tab
2025-01-13 23:00:03.41363 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/bams/processed.aligner_input_1.fastq ...
2025-01-13 23:00:03.41863 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/bams/processed.aligner_input_2.fastq ...
2025-01-13 23:00:03.4229 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/reports/shortReadReport_1 ...
2025-01-13 23:00:04.771272 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/reports/shortReadReport_2 ...
2025-01-13 23:00:07.332259 INFO::preprocessReads.R/preprocessReads: done
2025-01-13 23:00:07.427221 INFO::alignReads.R/alignReads: starting alignment...
2025-01-13 23:00:07.433616 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:00:10.66762 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:00:10.66953 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/chunks/chunk_000001/logs/progress.log
2025-01-13 23:00:13.468715 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2025-01-13 23:00:13.470392 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/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-01-13 23:00:16.145389 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-01-13 23:00:16.147695 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/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-01-13 23:00:18.90341 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-01-13 23:00:18.905916 DEBUG::tools.R/processChunks: done
2025-01-13 23:00:18.907368 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-01-13 23:00:19.132139 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-13 23:00:19.141349 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/results/test_pe.summary_alignment.tab
2025-01-13 23:00:19.148543 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/results/test_pe.summary_analyzed_bamstats.tab
2025-01-13 23:00:19.150282 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-13 23:00:19.44752 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.1ceb4d48660633/results/test_pe.summary_target_lengths.tab
2025-01-13 23:00:19.498586 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-13 23:00:19.499964 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:00:19.831079 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-13 23:00:19.834731 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-01-13 23:00:19.914658 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-01-13 23:00:19.919599 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-01-13 23:00:19.922658 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-01-13 23:00:19.924638 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:00:23.235976 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:00:23.237533 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/chunks/chunk_000001/logs/progress.log
2025-01-13 23:00:25.994088 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-01-13 23:00:25.995643 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/chunks/chunk_000002/logs/progress.log
2025-01-13 23:00:28.729491 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-01-13 23:00:28.730981 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/chunks/chunk_000003/logs/progress.log
2025-01-13 23:00:31.534348 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2025-01-13 23:00:31.535829 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/chunks/chunk_000004/logs/progress.log
2025-01-13 23:00:34.228385 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2025-01-13 23:00:34.264135 DEBUG::tools.R/processChunks: done
2025-01-13 23:00:34.267873 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:00:34.270655 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/results/test_pe.adapter_contaminated_1.RData
2025-01-13 23:00:34.274092 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-13 23:00:34.276122 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/results/test_pe.adapter_contaminated_2.RData
2025-01-13 23:00:34.287776 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-01-13 23:00:34.290248 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/results/test_pe.summary_preprocess.tab
2025-01-13 23:00:34.293996 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/bams/processed.aligner_input_1.fastq ...
2025-01-13 23:00:34.298588 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/bams/processed.aligner_input_2.fastq ...
2025-01-13 23:00:34.301853 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/reports/shortReadReport_1 ...
2025-01-13 23:00:35.699674 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.alignReads.sparsechunks.1ceb4d3379fb87/reports/shortReadReport_2 ...
2025-01-13 23:00:38.895502 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:00:39.116327 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-01-13 23:00:39.120669 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/RtmpOVZ2We/test.alignReadsOneSingleEnd.1ceb4d62322a74/bams/test.alignReads /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-01-13 23:00:39.347958 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-01-13 23:00:39.437304 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReadsOneSingleEnd.1ceb4d62322a74/results/test.alignReads.summary_alignment.tab
2025-01-13 23:00:39.485776 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.alignReadsOneSingleEnd.1ceb4d62322a74/results/test.alignReads.summary_analyzed_bamstats.tab
2025-01-13 23:00:39.487415 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/RtmpOVZ2We/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-01-13 23:00:39.772177 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.genotype.1ceb4d61195d31/results/test_pe.coverage.RData
2025-01-13 23:00:39.774072 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOVZ2We/test.genotype.1ceb4d61195d31/results/test_pe.coverage.bw
2025-01-13 23:00:39.889328 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.genotype.1ceb4d61195d31/results/test_pe.summary_coverage.tab
2025-01-13 23:00:39.891042 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-13 23:00:50.293107 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-13 23:00:50.37564 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-13 23:00:50.391834 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-13 23:00:50.393408 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.genotype.1ceb4d61195d31/results/test_pe.raw_variants.RData
2025-01-13 23:00:50.39572 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.genotype.1ceb4d61195d31/results/test_pe.filtered_variants.RData
2025-01-13 23:00:50.397086 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-13 23:00:50.398255 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-13 23:00:50.785998 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-13 23:00:50.787283 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-01-13 23:01:51.241172 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-13 23:01:51.651929 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-13 23:01:51.652908 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/RtmpOVZ2We/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-01-13 23:01:52.109251 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-13 23:02:02.323211 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-13 23:02:02.407692 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-13 23:02:02.42538 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-13 23:02:02.426804 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.1ceb4d15683786/results/test_pe.raw_variants.RData
2025-01-13 23:02:02.429197 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.1ceb4d15683786/results/test_pe.filtered_variants.RData
2025-01-13 23:02:02.430588 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:02:02.581379 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-13 23:02:12.751681 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-13 23:02:12.80897 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-13 23:02:12.825756 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-13 23:02:12.827156 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.filters.1ceb4d6850caaa/results/test_pe.raw_variants.RData
2025-01-13 23:02:12.829563 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.filters.1ceb4d6850caaa/results/test_pe.filtered_variants.RData
2025-01-13 23:02:12.830991 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-13 23:02:12.832373 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-13 23:02:22.828384 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-13 23:02:22.863024 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-13 23:02:22.878028 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-13 23:02:22.879274 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.filters.1ceb4d6850caaa/results/test_pe.raw_variants.RData
2025-01-13 23:02:22.88153 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.filters.1ceb4d6850caaa/results/test_pe.filtered_variants.RData
2025-01-13 23:02:22.88335 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:02:23.105685 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-13 23:02:23.107091 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-01-13 23:02:25.771194 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-13 23:02:25.840907 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-13 23:02:25.856372 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-13 23:02:25.857673 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.which.1ceb4d5380a94a/results/test_pe.raw_variants.RData
2025-01-13 23:02:25.859231 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.wrap.callVariants.which.1ceb4d5380a94a/results/test_pe.filtered_variants.RData
2025-01-13 23:02:25.860407 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:02:26.000137 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-13 23:02:26.00136 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:02:26.166134 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-13 23:02:26.369541 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-01-13 23:03:18.186126 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/gtywnmsa/merged/results/bla.coverage.RData
2025-01-13 23:03:18.188973 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOVZ2We/gtywnmsa/merged/results/bla.coverage.bw
2025-01-13 23:03:18.271477 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/gtywnmsa/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-01-13 23:03:19.485385 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/jvkbhsnq/merged/results/bla.coverage.RData
2025-01-13 23:03:19.487238 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOVZ2We/jvkbhsnq/merged/results/bla.coverage.bw
2025-01-13 23:03:19.499434 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/jvkbhsnq/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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/RtmpOVZ2We/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-01-13 23:03:20.795748 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-01-13 23:03:20.796777 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpOVZ2We/test.detectRRNA.1ceb4d13038417/bams/rRNA_contam/input1.fastq
2025-01-13 23:03:20.799812 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/RtmpOVZ2We/test.detectRRNA.1ceb4d13038417/bams/rRNA_contam/test_se /tmp/RtmpOVZ2We/test.detectRRNA.1ceb4d13038417/bams/rRNA_contam/input1.fastq 2>&1
2025-01-13 23:03:21.007286 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-01-13 23:03:21.00825 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:03:21.151766 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-01-13 23:03:21.152699 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpOVZ2We/test.detectRRNA.paired_end.1ceb4d37858450/bams/rRNA_contam/input1.fastq
2025-01-13 23:03:21.154186 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpOVZ2We/test.detectRRNA.paired_end.1ceb4d37858450/bams/rRNA_contam/input2.fastq
2025-01-13 23:03:21.156394 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/RtmpOVZ2We/test.detectRRNA.paired_end.1ceb4d37858450/bams/rRNA_contam/test_pe /tmp/RtmpOVZ2We/test.detectRRNA.paired_end.1ceb4d37858450/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpOVZ2We/test.detectRRNA.paired_end.1ceb4d37858450/bams/rRNA_contam/input2.fastq 2>&1
2025-01-13 23:03:21.392654 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-01-13 23:03:21.393664 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-01-13 23:03:21.412543 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/RtmpOVZ2We/test_get_rRNA_idsaoyqphfs/test_pe /tmp/RtmpOVZ2We/test_get_rRNA_idsaoyqphfs/1.fastq -a paired /tmp/RtmpOVZ2We/test_get_rRNA_idsaoyqphfs/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-01-13 23:03:21.660492 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/RtmpOVZ2We/test_get_rRNAIds_randomhjdwpies/test_pe /tmp/RtmpOVZ2We/test_get_rRNAIds_randomhjdwpies/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-01-13 23:03:21.912631 INFO::filterQuality.R/filterQuality: filterByLength...
2025-01-13 23:03:21.91403 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-01-13 23:03:21.914903 INFO::filterQuality.R/filterByLength: done
2025-01-13 23:03:21.959746 INFO::filterQuality.R/filterQuality: filterByLength...
2025-01-13 23:03:21.960704 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-01-13 23:03:21.961526 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-01-13 23:03:22.00889 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-13 23:03:22.01773 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-13 23:03:22.018825 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-13 23:03:22.023126 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-13 23:03:22.024116 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-13 23:03:22.02838 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-13 23:03:22.029322 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-13 23:03:22.033629 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.001
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") : 
  checkGATKJar() test needs gatk.path option set
 done successfully.



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:03:22.326233 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-01-13 23:03:22.32865 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/RtmpOVZ2We/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-01-13 23:03:22.507681 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-01-13 23:03:22.614302 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-13 23:03:22.61708 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-01-13 23:03:22.619355 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/RtmpOVZ2We/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-01-13 23:03:23.986964 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/RtmpOVZ2We/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-01-13 23:03:24.14544 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/RtmpOVZ2We/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-01-13 23:03:24.316095 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-01-13 23:03:24.389888 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-13 23:03:24.392464 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-01-13 23:03:24.394737 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/RtmpOVZ2We/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-01-13 23:03:24.627082 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-01-13 23:03:24.668284 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-13 23:03:24.670723 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-01-13 23:03:24.672891 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/RtmpOVZ2We/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/RtmpOVZ2We/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-01-13 23:03:25.456811 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-13 23:03:25.462946 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-01-13 23:03:25.466615 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-01-13 23:03:25.469112 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:03:29.097118 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:03:29.099421 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000001/logs/progress.log
2025-01-13 23:03:31.727219 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-01-13 23:03:31.72876 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000002/logs/progress.log
2025-01-13 23:03:34.416406 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-01-13 23:03:34.418072 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000003/logs/progress.log
2025-01-13 23:03:37.01899 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-01-13 23:03:37.059686 DEBUG::tools.R/processChunks: done
2025-01-13 23:03:37.062546 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:03:37.064298 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.adapter_contaminated_1.RData
2025-01-13 23:03:37.066466 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-13 23:03:37.068043 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.adapter_contaminated_2.RData
2025-01-13 23:03:37.076717 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-01-13 23:03:37.078573 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.summary_preprocess.tab
2025-01-13 23:03:37.081092 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/bams/processed.aligner_input_1.fastq ...
2025-01-13 23:03:37.085686 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/bams/processed.aligner_input_2.fastq ...
2025-01-13 23:03:37.089761 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/reports/shortReadReport_1 ...
2025-01-13 23:03:38.404792 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/reports/shortReadReport_2 ...
2025-01-13 23:03:39.451929 INFO::preprocessReads.R/preprocessReads: done
2025-01-13 23:03:39.578291 INFO::alignReads.R/alignReads: starting alignment...
2025-01-13 23:03:39.58246 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:03:42.483917 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:03:42.485822 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000001/logs/progress.log
2025-01-13 23:03:45.061501 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-01-13 23:03:45.062989 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/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-01-13 23:03:47.703273 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-01-13 23:03:47.704893 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/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-01-13 23:03:50.318327 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-01-13 23:03:50.32174 DEBUG::tools.R/processChunks: done
2025-01-13 23:03:50.323864 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-01-13 23:03:50.533476 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-13 23:03:50.541255 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.summary_alignment.tab
2025-01-13 23:03:50.548129 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.summary_analyzed_bamstats.tab
2025-01-13 23:03:50.550024 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-13 23:03:50.775015 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.summary_target_lengths.tab
2025-01-13 23:03:50.823008 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-13 23:03:50.824141 INFO::alignReads.R/alignReads: done
2025-01-13 23:03:50.947916 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-01-13 23:03:50.968541 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:03:54.003369 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:03:54.005052 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000001/logs/progress.log
2025-01-13 23:03:56.462306 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-01-13 23:03:56.465014 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000002/logs/progress.log
2025-01-13 23:03:58.943977 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2025-01-13 23:03:58.945589 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000003/logs/progress.log
2025-01-13 23:04:01.437498 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2025-01-13 23:04:01.440141 DEBUG::tools.R/processChunks: done
2025-01-13 23:04:01.442045 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-01-13 23:04:01.456936 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.counts_exon.tab
2025-01-13 23:04:01.468645 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.counts_exon_disjoint.tab
2025-01-13 23:04:01.476113 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.counts_gene.tab
2025-01-13 23:04:01.482012 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.counts_gene_coding.tab
2025-01-13 23:04:01.487426 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.counts_gene_exonic.tab
2025-01-13 23:04:01.493132 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.counts_intergenic.tab
2025-01-13 23:04:01.503346 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.counts_intron.tab
2025-01-13 23:04:01.506228 INFO::countGenomicFeatures.R/mergeCounts: done
2025-01-13 23:04:01.512089 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.summary_counts.tab
2025-01-13 23:04:01.513849 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-01-13 23:04:01.821578 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-01-13 23:04:01.822646 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-01-13 23:04:01.998313 INFO::coverage.R/calculateCoverage: starting...
2025-01-13 23:04:02.00304 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:04:05.370368 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:04:05.372175 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000001/logs/progress.log
2025-01-13 23:04:07.991303 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-01-13 23:04:07.998545 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000002/logs/progress.log
2025-01-13 23:04:10.588427 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-01-13 23:04:10.595177 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/chunks/chunk_000003/logs/progress.log
2025-01-13 23:04:13.096253 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2025-01-13 23:04:13.105251 DEBUG::tools.R/processChunks: done
2025-01-13 23:04:14.830536 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.coverage.RData
2025-01-13 23:04:14.83309 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.coverage.bw
2025-01-13 23:04:14.851858 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.summary_coverage.tab
2025-01-13 23:04:14.854119 INFO::coverage.R/calculateCoverage: done
2025-01-13 23:04:14.869059 INFO::analyzeVariants/analyzeVariants: starting ...
2025-01-13 23:04:15.586913 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-13 23:04:27.420959 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-13 23:04:27.694461 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-13 23:04:27.754014 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-13 23:04:27.758546 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.raw_variants.RData
2025-01-13 23:04:27.763452 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.filtered_variants.RData
2025-01-13 23:04:27.767279 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-13 23:04:27.770031 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-13 23:04:28.869558 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-13 23:04:29.240048 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/results/test_pe.summary_variants.tab
2025-01-13 23:04:29.252283 INFO::analyzeVariants/analyzeVariants: done
2025-01-13 23:04:29.268958 INFO::Pipeline run successful.
2025-01-13 23:04:29.89569 INFO::mergeLanes.R/doMergeLanes: starting...
2025-01-13 23:04:29.90306 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:04:29.906998 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.adapter_contaminated_1.RData
2025-01-13 23:04:29.912489 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-13 23:04:29.916361 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.adapter_contaminated_2.RData
2025-01-13 23:04:29.941168 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-01-13 23:04:29.946263 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.summary_preprocess.tab
2025-01-13 23:04:29.950949 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-01-13 23:04:30.605068 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-13 23:04:30.620138 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.summary_alignment.tab
2025-01-13 23:04:30.642019 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.summary_analyzed_bamstats.tab
2025-01-13 23:04:30.647353 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-13 23:04:31.199999 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.summary_target_lengths.tab
2025-01-13 23:04:31.29111 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-13 23:04:31.53139 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-01-13 23:04:31.585791 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.counts_exon.tab
2025-01-13 23:04:31.618485 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.counts_exon_disjoint.tab
2025-01-13 23:04:31.634231 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.counts_gene.tab
2025-01-13 23:04:31.647253 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.counts_gene_coding.tab
2025-01-13 23:04:31.661718 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.counts_gene_exonic.tab
2025-01-13 23:04:31.682436 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.counts_intergenic.tab
2025-01-13 23:04:31.714081 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.counts_intron.tab
2025-01-13 23:04:31.720259 INFO::countGenomicFeatures.R/mergeCounts: done
2025-01-13 23:04:31.738256 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.summary_counts.tab
2025-01-13 23:04:31.742904 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-01-13 23:04:32.200547 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-01-13 23:04:38.942278 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.coverage.RData
2025-01-13 23:04:38.956676 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.coverage.bw
2025-01-13 23:04:39.010424 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.summary_coverage.tab
2025-01-13 23:04:39.233503 INFO::analyzeVariants/analyzeVariants: starting ...
2025-01-13 23:04:39.572738 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-13 23:04:45.880348 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-13 23:04:46.023126 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-13 23:04:46.05514 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-13 23:04:46.058132 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.raw_variants.RData
2025-01-13 23:04:46.061494 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.filtered_variants.RData
2025-01-13 23:04:46.063991 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-13 23:04:46.065872 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-13 23:04:46.528679 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-13 23:04:46.817262 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.mergeLanes.1ceb4d75e22f22/merged/results/merged.summary_variants.tab
2025-01-13 23:04:46.822904 INFO::analyzeVariants/analyzeVariants: done
2025-01-13 23:04:46.831079 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0.001 0.002 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.001 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/RtmpOVZ2We/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-01-13 23:04:47.609498 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-13 23:04:47.623975 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-01-13 23:04:47.633669 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-01-13 23:04:47.640328 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:04:54.915035 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:04:54.919721 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/chunks/chunk_000001/logs/progress.log
2025-01-13 23:04:58.209742 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.055 minutes
2025-01-13 23:04:58.321797 DEBUG::tools.R/processChunks: done
2025-01-13 23:04:58.327274 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:04:58.330803 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/results/test_pe.adapter_contaminated_1.RData
2025-01-13 23:04:58.334593 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-13 23:04:58.337801 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/results/test_pe.adapter_contaminated_2.RData
2025-01-13 23:04:58.354883 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-01-13 23:04:58.35965 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/results/test_pe.summary_preprocess.tab
2025-01-13 23:04:58.364221 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/bams/processed.aligner_input_1.fastq ...
2025-01-13 23:04:58.373699 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/bams/processed.aligner_input_2.fastq ...
2025-01-13 23:04:58.381966 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/reports/shortReadReport_1 ...
2025-01-13 23:05:01.801327 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.preprocessReads.1ceb4d13d085e2/reports/shortReadReport_2 ...
2025-01-13 23:05:04.640392 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:05:05.130651 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-13 23:05:05.139546 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-01-13 23:05:05.147138 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-01-13 23:05:05.151583 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:05:09.338533 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:05:09.340217 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/chunks/chunk_000001/logs/progress.log
2025-01-13 23:05:12.02957 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-01-13 23:05:12.031701 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/chunks/chunk_000002/logs/progress.log
2025-01-13 23:05:14.654597 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-01-13 23:05:14.656134 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/chunks/chunk_000003/logs/progress.log
2025-01-13 23:05:17.231748 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-01-13 23:05:17.27507 DEBUG::tools.R/processChunks: done
2025-01-13 23:05:17.27784 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:05:17.279652 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/results/test_pe.adapter_contaminated_1.RData
2025-01-13 23:05:17.281823 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-13 23:05:17.28343 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/results/test_pe.adapter_contaminated_2.RData
2025-01-13 23:05:17.291717 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-01-13 23:05:17.293455 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/results/test_pe.summary_preprocess.tab
2025-01-13 23:05:17.295763 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/bams/processed.aligner_input_1.fastq ...
2025-01-13 23:05:17.299743 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/bams/processed.aligner_input_2.fastq ...
2025-01-13 23:05:17.302775 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/reports/shortReadReport_1 ...
2025-01-13 23:05:18.600946 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.preprocessReads.minichunks.1ceb4d3ec7e72b/reports/shortReadReport_2 ...
2025-01-13 23:05:19.661554 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpOVZ2We/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-01-13 23:05:19.926107 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-13 23:05:19.946772 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-01-13 23:05:19.949572 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:05:22.906488 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:05:22.907964 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpOVZ2We/test.preprocessReads_single_end.1ceb4d1e558f23/chunks/chunk_000001/logs/progress.log
2025-01-13 23:05:25.280954 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2025-01-13 23:05:25.292911 DEBUG::tools.R/processChunks: done
2025-01-13 23:05:25.295667 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:05:25.297495 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads_single_end.1ceb4d1e558f23/results/test_se.adapter_contaminated_1.RData
2025-01-13 23:05:25.305369 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-01-13 23:05:25.307452 INFO::io.R/saveWithID: saving file= /tmp/RtmpOVZ2We/test.preprocessReads_single_end.1ceb4d1e558f23/results/test_se.summary_preprocess.tab
2025-01-13 23:05:25.309598 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpOVZ2We/test.preprocessReads_single_end.1ceb4d1e558f23/bams/processed.aligner_input_1.fastq ...
2025-01-13 23:05:25.313413 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpOVZ2We/test.preprocessReads_single_end.1ceb4d1e558f23/reports/shortReadReport_1 ...
2025-01-13 23:05:26.684913 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-01-13 23:05:27.27607 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-13 23:05:27.297185 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-01-13 23:05:27.30254 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-01-13 23:05:27.305419 DEBUG::tools.R/processChunks: starting...
2025-01-13 23:05:30.362392 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-13 23:05:30.363986 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-01-13 23:05:33.097251 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-01-13 23:05:33.148216 DEBUG::tools.R/processChunks: done
2025-01-13 23:05:33.150672 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-13 23:05:33.152414 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-01-13 23:05:33.154422 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-13 23:05:33.155992 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-01-13 23:05:33.16361 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-01-13 23:05:33.165692 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-01-13 23:05:33.167786 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-01-13 23:05:33.171692 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-01-13 23:05:33.17518 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-01-13 23:06:27.301988 DEBUG::tools.R/traceMem: wired.mem=33.087709 GiB
2025-01-13 23:07:27.370411 DEBUG::tools.R/traceMem: wired.mem=39.476027 GiB
2025-01-13 23:08:27.436831 DEBUG::tools.R/traceMem: wired.mem=-37.866226 GiB
2025-01-13 23:09:27.504432 DEBUG::tools.R/traceMem: wired.mem=-31.523021 GiB
2025-01-13 23:10:27.571331 DEBUG::tools.R/traceMem: wired.mem=-35.356500 GiB
2025-01-13 23:11:27.637984 DEBUG::tools.R/traceMem: wired.mem=-24.890343 GiB
2025-01-13 23:12:27.705858 DEBUG::tools.R/traceMem: wired.mem=-33.752949 GiB
2025-01-13 23:13:27.772331 DEBUG::tools.R/traceMem: wired.mem=-32.543310 GiB
2025-01-13 23:14:27.83926 DEBUG::tools.R/traceMem: wired.mem=-28.591718 GiB
2025-01-13 23:15:27.907319 DEBUG::tools.R/traceMem: wired.mem=-33.581974 GiB
2025-01-13 23:16:27.973417 DEBUG::tools.R/traceMem: wired.mem=-31.349195 GiB
2025-01-13 23:17:28.040404 DEBUG::tools.R/traceMem: wired.mem=-27.848131 GiB
2025-01-13 23:18:28.106375 DEBUG::tools.R/traceMem: wired.mem=-29.240304 GiB
2025-01-13 23:19:28.173428 DEBUG::tools.R/traceMem: wired.mem=-29.564076 GiB
2025-01-13 23:20:28.241142 DEBUG::tools.R/traceMem: wired.mem=-26.979860 GiB
2025-01-13 23:21:28.30634 DEBUG::tools.R/traceMem: wired.mem=-34.183479 GiB
2025-01-13 23:22:28.372485 DEBUG::tools.R/traceMem: wired.mem=-31.744041 GiB
2025-01-13 23:23:28.438022 DEBUG::tools.R/traceMem: wired.mem=-36.006568 GiB
2025-01-13 23:24:28.504518 DEBUG::tools.R/traceMem: wired.mem=-30.776058 GiB
2025-01-13 23:25:28.571485 DEBUG::tools.R/traceMem: wired.mem=-40.864522 GiB
2025-01-13 23:26:28.635808 DEBUG::tools.R/traceMem: wired.mem=-30.644445 GiB
2025-01-13 23:27:28.7027 DEBUG::tools.R/traceMem: wired.mem=-25.419489 GiB
2025-01-13 23:28:28.77042 DEBUG::tools.R/traceMem: wired.mem=-33.590288 GiB
2025-01-13 23:29:28.835865 DEBUG::tools.R/traceMem: wired.mem=-31.327527 GiB
2025-01-13 23:30:28.902665 DEBUG::tools.R/traceMem: wired.mem=-24.897511 GiB
2025-01-13 23:31:28.970366 DEBUG::tools.R/traceMem: wired.mem=-27.037508 GiB
2025-01-13 23:32:29.036738 DEBUG::tools.R/traceMem: wired.mem=-29.145661 GiB
2025-01-13 23:33:29.103648 DEBUG::tools.R/traceMem: wired.mem=-25.931350 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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