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

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo1	Linux (Ubuntu 24.04.1 LTS)	x86_64	R Under development (unstable) (2025-03-13 r87965) -- "Unsuffered Consequences"	4779
palomino7	Windows Server 2022 Datacenter	x64	R Under development (unstable) (2025-03-01 r87860 ucrt) -- "Unsuffered Consequences"	4550
lconway	macOS 12.7.1 Monterey	x86_64	R Under development (unstable) (2025-03-02 r87868) -- "Unsuffered Consequences"	4578
kjohnson3	macOS 13.7.1 Ventura	arm64	R Under development (unstable) (2025-03-02 r87868) -- "Unsuffered Consequences"	4530
kunpeng2	Linux (openEuler 24.03 LTS)	aarch64	R Under development (unstable) (2025-02-19 r87757) -- "Unsuffered Consequences"	4461
Click on any hostname to see more info about the system (e.g. compilers) () as reported by 'uname -p', except on Windows and Mac OS X*

CHECK results for HTSeqGenie on nebbiolo1

To the developers/maintainers of the HTSeqGenie package:
- Allow up to 24 hours (and sometimes 48 hours) for your latest push to git@git.bioconductor.org:packages/HTSeqGenie.git to reflect on this report. See Troubleshooting Build Report for more information.
- Use the following Renviron settings to reproduce errors and warnings.
- If 'R CMD check' started to fail recently on the Linux builder(s) over a missing dependency, add the missing dependency to 'Suggests:' in your DESCRIPTION file. See Renviron.bioc for more information.

raw results

Summary

Package: HTSeqGenie

Version: 4.37.1

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

StartedAt: 2025-03-23 23:03:56 -0400 (Sun, 23 Mar 2025)

EndedAt: 2025-03-23 23:43:56 -0400 (Sun, 23 Mar 2025)

EllapsedTime: 2400.3 seconds

RetCode: None

Status: TIMEOUT

CheckDir: HTSeqGenie.Rcheck

Warnings: NA

Command output

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


* using log directory ‘/home/biocbuild/bbs-3.21-bioc/meat/HTSeqGenie.Rcheck’
* using R Under development (unstable) (2025-03-13 r87965)
* using platform: x86_64-pc-linux-gnu
* R was compiled by
    gcc (Ubuntu 13.3.0-6ubuntu2~24.04) 13.3.0
    GNU Fortran (Ubuntu 13.3.0-6ubuntu2~24.04) 13.3.0
* running under: Ubuntu 24.04.2 LTS
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.37.1’
* checking package namespace information ... OK
* checking package dependencies ... OK
* checking if this is a source package ... OK
* checking if there is a namespace ... OK
* checking for hidden files and directories ... NOTE
Found the following hidden files and directories:
  .BBSoptions
These were most likely included in error. See section ‘Package
structure’ in the ‘Writing R Extensions’ manual.
* checking for portable file names ... OK
* checking for sufficient/correct file permissions ... OK
* checking whether package ‘HTSeqGenie’ can be installed ... OK
* checking installed package size ... OK
* checking package directory ... OK
* checking ‘build’ directory ... OK
* checking DESCRIPTION meta-information ... NOTE
Malformed Title field: should not end in a period.
* checking top-level files ... OK
* checking for left-over files ... OK
* checking index information ... OK
* checking package subdirectories ... OK
* checking code files for non-ASCII characters ... OK
* checking R files for syntax errors ... OK
* checking whether the package can be loaded ... OK
* checking whether the package can be loaded with stated dependencies ... OK
* checking whether the package can be unloaded cleanly ... OK
* checking whether the namespace can be loaded with stated dependencies ... OK
* checking whether the namespace can be unloaded cleanly ... OK
* checking loading without being on the library search path ... OK
* checking whether startup messages can be suppressed ... OK
* checking dependencies in R code ... NOTE
Unexported objects imported by ':::' calls:
  ‘ShortRead:::.set_omp_threads’ ‘gmapR:::..gsnap’ ‘gmapR:::GeneGenome’
  ‘gmapR:::checkPackageInstalled’ ‘gmapR:::getDefaultGmapGenomePath’
  ‘gmapR:::getGeneRoi’ ‘gmapR:::subsetRegion’ ‘parallel:::mckill’
  See the note in ?`:::` about the use of this operator.
* checking S3 generic/method consistency ... OK
* checking replacement functions ... OK
* checking foreign function calls ... NOTE
Foreign function call to a different package:
  .Call(ShortRead:::.set_omp_threads, ...)
See chapter ‘System and foreign language interfaces’ in the ‘Writing R
Extensions’ manual.
* checking R code for possible problems ... NOTE
.makePreprocessAlignPlots: no visible binding for global variable
  ‘data’
.plot.in.out.min.max.readlength: no visible global function definition
  for ‘median’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.lfqs’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.chunkid’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.subsampling_filter’
FastQStreamer.init: no visible binding for '<<-' assignment to
  ‘FastQStreamer.max_nbchunks’
addHandler: no visible binding for '<<-' assignment to
  ‘logging.handlers’
addHandler: no visible binding for global variable ‘logging.handlers’
addHandler: no visible binding for '<<-' assignment to ‘logging.file’
buildAnyFastaGenome: no visible global function definition for ‘getSeq’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘gaps’
buildGenomicFeaturesFromTxDb: no visible global function definition for
  ‘ranges’
buildTP53FastaGenome: no visible global function definition for
  ‘getSeq’
buildTallyParam: no visible global function definition for ‘seqinfo’
computeCoverage: no visible global function definition for ‘resize’
computeCoverage: no visible global function definition for ‘coverage’
estimateCutoffs : <anonymous>: no visible binding for global variable
  ‘quantile’
getGenomeSegments: no visible global function definition for ‘seqinfo’
hashVariants: no visible global function definition for ‘ranges’
isAboveQualityThresh: no visible global function definition for ‘Views’
isAboveQualityThresh: no visible global function definition for
  ‘viewMeans’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.n’
listIterator.init: no visible binding for '<<-' assignment to
  ‘listIterator.x’
logReset: no visible binding for '<<-' assignment to ‘logging.handlers’
logReset: no visible binding for '<<-' assignment to ‘logging.loglevel’
logReset: no visible binding for '<<-' assignment to ‘logging.file’
loglevel: no visible binding for global variable ‘logging.loglevel’
loglevel: no visible binding for global variable ‘logging.handlers’
processChunks : tracefun: no visible binding for global variable
  ‘sjobs’
processChunks : tracefun: no visible binding for global variable
  ‘chunkid’
setLevel: no visible binding for '<<-' assignment to ‘logging.loglevel’
statCountFeatures: no visible global function definition for ‘quantile’
truncateReads: no visible global function definition for ‘subseq’
vcfStat: no visible global function definition for ‘quantile’
writeToFile: no visible binding for global variable ‘logging.file’
Undefined global functions or variables:
  Views chunkid coverage data gaps getSeq logging.file logging.handlers
  logging.loglevel median quantile ranges resize seqinfo sjobs subseq
  viewMeans
Consider adding
  importFrom("stats", "median", "quantile")
  importFrom("utils", "data")
to your NAMESPACE file.
* checking Rd files ... NOTE
checkRd: (-1) calculateTargetLengths.Rd:17: Lost braces; missing escapes or markup?
    17 | Target length table and writes two files in {save_dir}/reports/images/TargetLenghts.[pdf|png]"
       |                                             ^
checkRd: (-1) initLog.Rd:18: Lost braces; missing escapes or markup?
    18 | Setup logging file in {save_dir}/progress.log
       |                       ^
* checking Rd metadata ... OK
* checking Rd cross-references ... OK
* checking for missing documentation entries ... OK
* checking for code/documentation mismatches ... OK
* checking Rd \usage sections ... NOTE
Documented arguments not in \usage in Rd file 'findVariantFile.Rd':
  ‘dir_path’

Documented arguments not in \usage in Rd file 'logdebug.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'logerror.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'loginfo.Rd':
  ‘...’

Documented arguments not in \usage in Rd file 'logwarn.Rd':
  ‘...’

Functions with \usage entries need to have the appropriate \alias
entries, and all their arguments documented.
The \usage entries must correspond to syntactically valid R code.
See chapter ‘Writing R documentation files’ in the ‘Writing R
Extensions’ manual.
* checking Rd contents ... OK
* checking for unstated dependencies in examples ... OK
* checking files in ‘vignettes’ ... OK
* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
  Running ‘doRUnit.R’

Installation output

HTSeqGenie.Rcheck/00install.out

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


* installing to library ‘/home/biocbuild/bbs-3.21-bioc/R/site-library’
* installing *source* package ‘HTSeqGenie’ ...
** this is package ‘HTSeqGenie’ version ‘4.37.1’
** using staged installation
** R
** inst
** byte-compile and prepare package for lazy loading
** help
*** installing help indices
** building package indices
** installing vignettes
** testing if installed package can be loaded from temporary location
Warning in fun(libname, pkgname) :
  Package 'HTSeqGenie' is deprecated and will be removed from
  Bioconductor version 3.22
** testing if installed package can be loaded from final location
Warning in fun(libname, pkgname) :
  Package 'HTSeqGenie' is deprecated and will be removed from
  Bioconductor version 3.22
** testing if installed package keeps a record of temporary installation path
* DONE (HTSeqGenie)

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R Under development (unstable) (2025-03-13 r87965) -- "Unsuffered Consequences"
Copyright (C) 2025 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu

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

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

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

> library("HTSeqGenie")
Loading required package: gmapR
Loading required package: GenomeInfoDb
Loading required package: BiocGenerics
Loading required package: generics

Attaching package: 'generics'

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

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


Attaching package: 'BiocGenerics'

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

    IQR, mad, sd, var, xtabs

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

    Filter, Find, Map, Position, Reduce, anyDuplicated, aperm, append,
    as.data.frame, basename, cbind, colnames, dirname, do.call,
    duplicated, eval, evalq, get, grep, grepl, is.unsorted, lapply,
    mapply, match, mget, order, paste, pmax, pmax.int, pmin, pmin.int,
    rank, rbind, rownames, sapply, saveRDS, table, tapply, unique,
    unsplit, which.max, which.min

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

The following object is masked from 'package:utils':

    findMatches

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

    I, expand.grid, unname

Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector

Attaching package: 'Biostrings'

The following object is masked from 'package:base':

    strsplit

Loading required package: ShortRead
Loading required package: BiocParallel
Loading required package: GenomicAlignments
Loading required package: SummarizedExperiment
Loading required package: MatrixGenerics
Loading required package: matrixStats

Attaching package: 'MatrixGenerics'

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

    colAlls, colAnyNAs, colAnys, colAvgsPerRowSet, colCollapse,
    colCounts, colCummaxs, colCummins, colCumprods, colCumsums,
    colDiffs, colIQRDiffs, colIQRs, colLogSumExps, colMadDiffs,
    colMads, colMaxs, colMeans2, colMedians, colMins, colOrderStats,
    colProds, colQuantiles, colRanges, colRanks, colSdDiffs, colSds,
    colSums2, colTabulates, colVarDiffs, colVars, colWeightedMads,
    colWeightedMeans, colWeightedMedians, colWeightedSds,
    colWeightedVars, rowAlls, rowAnyNAs, rowAnys, rowAvgsPerColSet,
    rowCollapse, rowCounts, rowCummaxs, rowCummins, rowCumprods,
    rowCumsums, rowDiffs, rowIQRDiffs, rowIQRs, rowLogSumExps,
    rowMadDiffs, rowMads, rowMaxs, rowMeans2, rowMedians, rowMins,
    rowOrderStats, rowProds, rowQuantiles, rowRanges, rowRanks,
    rowSdDiffs, rowSds, rowSums2, rowTabulates, rowVarDiffs, rowVars,
    rowWeightedMads, rowWeightedMeans, rowWeightedMedians,
    rowWeightedSds, rowWeightedVars

Loading required package: Biobase
Welcome to Bioconductor

    Vignettes contain introductory material; view with
    'browseVignettes()'. To cite Bioconductor, see
    'citation("Biobase")', and for packages 'citation("pkgname")'.


Attaching package: 'Biobase'

The following object is masked from 'package:MatrixGenerics':

    rowMedians

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

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

The following object is masked from 'package:base':

    tabulate

Warning message:
In fun(libname, pkgname) :
  Package 'HTSeqGenie' is deprecated and will be removed from
  Bioconductor version 3.22
> 
> source(getPackageFile("unitTests/runTests.R"))
Loading required package: GenomicFeatures
Loading required package: AnnotationDbi
did not source anything in dirname= ./R 


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:09:37.53134 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-23 23:09:37.539763 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:09:37.543558 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-23 23:09:37.545784 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:09:40.41749 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:09:40.418914 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/chunks/chunk_000001/logs/progress.log
2025-03-23 23:09:43.133769 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-03-23 23:09:43.135607 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/chunks/chunk_000002/logs/progress.log
2025-03-23 23:09:45.859922 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-03-23 23:09:45.861838 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/chunks/chunk_000003/logs/progress.log
2025-03-23 23:09:48.585641 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-23 23:09:48.612197 DEBUG::tools.R/processChunks: done
2025-03-23 23:09:48.615594 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:09:48.617606 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/results/test_pe.adapter_contaminated_1.RData
2025-03-23 23:09:48.620081 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-23 23:09:48.621566 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/results/test_pe.adapter_contaminated_2.RData
2025-03-23 23:09:48.629746 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-23 23:09:48.631741 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/results/test_pe.summary_preprocess.tab
2025-03-23 23:09:48.634634 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/bams/processed.aligner_input_1.fastq ...
2025-03-23 23:09:48.638366 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/bams/processed.aligner_input_2.fastq ...
2025-03-23 23:09:48.641282 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/reports/shortReadReport_1 ...
2025-03-23 23:09:49.951461 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/reports/shortReadReport_2 ...
2025-03-23 23:09:52.391809 INFO::preprocessReads.R/preprocessReads: done
2025-03-23 23:09:52.475292 INFO::alignReads.R/alignReads: starting alignment...
2025-03-23 23:09:52.48147 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:09:55.484624 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:09:55.48638 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/chunks/chunk_000001/logs/progress.log
2025-03-23 23:09:58.324646 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2025-03-23 23:09:58.326378 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-23 23:10:01.025506 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-03-23 23:10:01.027172 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-23 23:10:03.720508 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-23 23:10:03.724188 DEBUG::tools.R/processChunks: done
2025-03-23 23:10:03.726272 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-23 23:10:03.967611 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-23 23:10:03.977107 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/results/test_pe.summary_alignment.tab
2025-03-23 23:10:03.984776 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/results/test_pe.summary_analyzed_bamstats.tab
2025-03-23 23:10:03.986686 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-23 23:10:04.2359 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.170649699ab836/results/test_pe.summary_target_lengths.tab
2025-03-23 23:10:04.284802 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-23 23:10:04.286039 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:10:04.595834 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-23 23:10:04.59883 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:10:04.662178 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-03-23 23:10:04.666924 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:10:04.669971 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-23 23:10:04.671941 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:10:07.466748 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:10:07.469732 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/chunks/chunk_000001/logs/progress.log
2025-03-23 23:10:10.19199 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-03-23 23:10:10.193547 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/chunks/chunk_000002/logs/progress.log
2025-03-23 23:10:12.837858 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-23 23:10:12.83912 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/chunks/chunk_000003/logs/progress.log
2025-03-23 23:10:15.551185 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-23 23:10:15.552426 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/chunks/chunk_000004/logs/progress.log
2025-03-23 23:10:18.173296 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2025-03-23 23:10:18.200234 DEBUG::tools.R/processChunks: done
2025-03-23 23:10:18.205802 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:10:18.208469 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/results/test_pe.adapter_contaminated_1.RData
2025-03-23 23:10:18.211851 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-23 23:10:18.213857 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/results/test_pe.adapter_contaminated_2.RData
2025-03-23 23:10:18.224687 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-23 23:10:18.227089 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/results/test_pe.summary_preprocess.tab
2025-03-23 23:10:18.230818 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/bams/processed.aligner_input_1.fastq ...
2025-03-23 23:10:18.235502 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/bams/processed.aligner_input_2.fastq ...
2025-03-23 23:10:18.239105 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/reports/shortReadReport_1 ...
2025-03-23 23:10:19.509207 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.alignReads.sparsechunks.170649419d3b33/reports/shortReadReport_2 ...
2025-03-23 23:10:21.928342 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:10:22.073067 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-03-23 23:10:22.077275 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/RtmpQNmbEr/test.alignReadsOneSingleEnd.1706493f282002/bams/test.alignReads /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-03-23 23:10:22.294125 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-03-23 23:10:22.379161 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReadsOneSingleEnd.1706493f282002/results/test.alignReads.summary_alignment.tab
2025-03-23 23:10:22.428532 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.alignReadsOneSingleEnd.1706493f282002/results/test.alignReads.summary_analyzed_bamstats.tab
2025-03-23 23:10:22.430051 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.001 0.001 0.001
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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:10:22.743645 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.genotype.1706496fdc700e/results/test_pe.coverage.RData
2025-03-23 23:10:22.745488 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpQNmbEr/test.genotype.1706496fdc700e/results/test_pe.coverage.bw
2025-03-23 23:10:22.865265 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.genotype.1706496fdc700e/results/test_pe.summary_coverage.tab
2025-03-23 23:10:22.867043 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-23 23:10:32.769446 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-23 23:10:32.854661 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-23 23:10:32.871832 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-23 23:10:32.873474 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.genotype.1706496fdc700e/results/test_pe.raw_variants.RData
2025-03-23 23:10:32.876004 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.genotype.1706496fdc700e/results/test_pe.filtered_variants.RData
2025-03-23 23:10:32.877397 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-23 23:10:32.878605 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-23 23:10:33.288635 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-23 23:10:33.289885 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-03-23 23:11:34.591283 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-23 23:11:35.043309 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-23 23:11:35.044261 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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:11:35.460925 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-23 23:11:45.172758 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-23 23:11:45.251749 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-23 23:11:45.269202 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-23 23:11:45.27063 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.170649e1d5401/results/test_pe.raw_variants.RData
2025-03-23 23:11:45.273146 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.170649e1d5401/results/test_pe.filtered_variants.RData
2025-03-23 23:11:45.274503 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:11:45.423702 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-23 23:11:54.873266 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-23 23:11:54.928052 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-23 23:11:54.944237 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-23 23:11:54.945617 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.filters.1706496378cd14/results/test_pe.raw_variants.RData
2025-03-23 23:11:54.948016 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.filters.1706496378cd14/results/test_pe.filtered_variants.RData
2025-03-23 23:11:54.949308 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-23 23:11:54.950852 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-23 23:12:04.508801 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-23 23:12:04.547914 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-23 23:12:04.565523 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-23 23:12:04.566965 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.filters.1706496378cd14/results/test_pe.raw_variants.RData
2025-03-23 23:12:04.569775 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.filters.1706496378cd14/results/test_pe.filtered_variants.RData
2025-03-23 23:12:04.571899 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:12:04.837588 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-23 23:12:04.839465 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-03-23 23:12:07.495238 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-23 23:12:07.564966 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-23 23:12:07.580621 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-23 23:12:07.581998 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.which.17064969387e1/results/test_pe.raw_variants.RData
2025-03-23 23:12:07.583552 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.wrap.callVariants.which.17064969387e1/results/test_pe.filtered_variants.RData
2025-03-23 23:12:07.584788 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:12:07.719053 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-23 23:12:07.720375 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:12:07.886477 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-23 23:12:08.089007 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.isFirstFragment  ...  done successfully.



Executing test function test.buildCountsGRangesList  ...   403 genes were dropped because they have exons located on both strands of the
  same reference sequence or on more than one reference sequence, so cannot be
  represented by a single genomic range.
  Use 'single.strand.genes.only=FALSE' to get all the genes in a GRangesList
  object, or use suppressMessages() to suppress this message.
 done successfully.



Executing test function test.generateSingleGeneDERs  ...  done successfully.



Executing test function test.computeCoverage  ...  done successfully.



Executing test function test.isSparse  ...  done successfully.



Executing test function test.mergeCoverage  ... 2025-03-23 23:13:01.864839 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/okpsetxq/merged/results/bla.coverage.RData
2025-03-23 23:13:01.867992 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpQNmbEr/okpsetxq/merged/results/bla.coverage.bw
2025-03-23 23:13:01.953434 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/okpsetxq/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-03-23 23:13:03.137575 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/jsnertpq/merged/results/bla.coverage.RData
2025-03-23 23:13:03.139337 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpQNmbEr/jsnertpq/merged/results/bla.coverage.bw
2025-03-23 23:13:03.151111 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/jsnertpq/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:04.361338 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-23 23:13:04.362488 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpQNmbEr/test.detectRRNA.17064944cdf73f/bams/rRNA_contam/input1.fastq
2025-03-23 23:13:04.365727 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/RtmpQNmbEr/test.detectRRNA.17064944cdf73f/bams/rRNA_contam/test_se /tmp/RtmpQNmbEr/test.detectRRNA.17064944cdf73f/bams/rRNA_contam/input1.fastq 2>&1
2025-03-23 23:13:04.540506 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-23 23:13:04.541501 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:04.698718 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-23 23:13:04.700722 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpQNmbEr/test.detectRRNA.paired_end.1706492a2a348a/bams/rRNA_contam/input1.fastq
2025-03-23 23:13:04.702275 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpQNmbEr/test.detectRRNA.paired_end.1706492a2a348a/bams/rRNA_contam/input2.fastq
2025-03-23 23:13:04.704473 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/RtmpQNmbEr/test.detectRRNA.paired_end.1706492a2a348a/bams/rRNA_contam/test_pe /tmp/RtmpQNmbEr/test.detectRRNA.paired_end.1706492a2a348a/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpQNmbEr/test.detectRRNA.paired_end.1706492a2a348a/bams/rRNA_contam/input2.fastq 2>&1
2025-03-23 23:13:04.947741 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-23 23:13:04.948886 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



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



Executing test function test.getRRNAIds_random  ... 2025-03-23 23:13:05.225249 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/RtmpQNmbEr/test_get_rRNAIds_randomvwuxpmqz/test_pe /tmp/RtmpQNmbEr/test_get_rRNAIds_randomvwuxpmqz/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-03-23 23:13:05.510007 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-23 23:13:05.512157 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-03-23 23:13:05.51353 INFO::filterQuality.R/filterByLength: done
2025-03-23 23:13:05.581709 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-23 23:13:05.58267 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-03-23 23:13:05.583531 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-03-23 23:13:05.634351 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-23 23:13:05.643477 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-23 23:13:05.644648 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-23 23:13:05.649465 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-23 23:13:05.65058 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-23 23:13:05.655066 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-23 23:13:05.656045 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-23 23:13:05.660569 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:05.928594 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:05.931 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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:06.104908 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:06.174327 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-23 23:13:06.177013 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:06.179204 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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:06.380545 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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:06.526041 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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:06.666088 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:06.709757 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-23 23:13:06.712232 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:06.714462 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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:06.907749 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:06.954385 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-23 23:13:06.95694 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:06.959322 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/RtmpQNmbEr/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/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:13:07.671667 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-23 23:13:07.677085 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:13:07.680293 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-23 23:13:07.682478 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:13:10.537606 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:13:10.539087 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000001/logs/progress.log
2025-03-23 23:13:13.147572 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-23 23:13:13.149159 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000002/logs/progress.log
2025-03-23 23:13:15.748396 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-03-23 23:13:15.749759 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000003/logs/progress.log
2025-03-23 23:13:18.388307 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-03-23 23:13:18.44262 DEBUG::tools.R/processChunks: done
2025-03-23 23:13:18.446658 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:13:18.448848 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.adapter_contaminated_1.RData
2025-03-23 23:13:18.451196 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-23 23:13:18.452815 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.adapter_contaminated_2.RData
2025-03-23 23:13:18.462094 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-23 23:13:18.464113 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.summary_preprocess.tab
2025-03-23 23:13:18.466774 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/bams/processed.aligner_input_1.fastq ...
2025-03-23 23:13:18.470913 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/bams/processed.aligner_input_2.fastq ...
2025-03-23 23:13:18.47432 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/reports/shortReadReport_1 ...
2025-03-23 23:13:19.770458 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/reports/shortReadReport_2 ...
2025-03-23 23:13:20.851911 INFO::preprocessReads.R/preprocessReads: done
2025-03-23 23:13:20.938906 INFO::alignReads.R/alignReads: starting alignment...
2025-03-23 23:13:20.943262 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:13:23.805132 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:13:23.806741 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000001/logs/progress.log
2025-03-23 23:13:26.393039 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-23 23:13:26.394512 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-23 23:13:29.032631 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-23 23:13:29.034391 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-23 23:13:31.644446 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-03-23 23:13:31.646887 DEBUG::tools.R/processChunks: done
2025-03-23 23:13:31.648356 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-23 23:13:31.827218 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-23 23:13:31.833997 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.summary_alignment.tab
2025-03-23 23:13:31.840181 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.summary_analyzed_bamstats.tab
2025-03-23 23:13:31.841816 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-23 23:13:32.055299 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.summary_target_lengths.tab
2025-03-23 23:13:32.09989 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-23 23:13:32.100949 INFO::alignReads.R/alignReads: done
2025-03-23 23:13:32.202726 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-03-23 23:13:32.223819 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:13:35.216987 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:13:35.218788 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000001/logs/progress.log
2025-03-23 23:13:37.658038 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-03-23 23:13:37.660208 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000002/logs/progress.log
2025-03-23 23:13:40.099675 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2025-03-23 23:13:40.101434 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000003/logs/progress.log
2025-03-23 23:13:42.978312 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2025-03-23 23:13:42.98142 DEBUG::tools.R/processChunks: done
2025-03-23 23:13:42.983503 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-23 23:13:43.007904 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.counts_exon.tab
2025-03-23 23:13:43.028671 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.counts_exon_disjoint.tab
2025-03-23 23:13:43.039771 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.counts_gene.tab
2025-03-23 23:13:43.047769 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.counts_gene_coding.tab
2025-03-23 23:13:43.054996 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.counts_gene_exonic.tab
2025-03-23 23:13:43.06171 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.counts_intergenic.tab
2025-03-23 23:13:43.072715 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.counts_intron.tab
2025-03-23 23:13:43.075747 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-23 23:13:43.081536 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.summary_counts.tab
2025-03-23 23:13:43.083309 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-23 23:13:43.398983 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-23 23:13:43.400198 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-03-23 23:13:43.518408 INFO::coverage.R/calculateCoverage: starting...
2025-03-23 23:13:43.523956 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:13:49.332266 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:13:49.335219 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000001/logs/progress.log
2025-03-23 23:13:51.800485 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-03-23 23:13:51.807917 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000002/logs/progress.log
2025-03-23 23:13:54.433374 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-23 23:13:54.440336 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/chunks/chunk_000003/logs/progress.log
2025-03-23 23:13:56.845535 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.04 minutes
2025-03-23 23:13:56.857262 DEBUG::tools.R/processChunks: done
2025-03-23 23:14:01.388368 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.coverage.RData
2025-03-23 23:14:01.396437 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.coverage.bw
2025-03-23 23:14:01.47285 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.summary_coverage.tab
2025-03-23 23:14:01.48039 INFO::coverage.R/calculateCoverage: done
2025-03-23 23:14:01.488031 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-23 23:14:02.055459 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-23 23:14:10.793774 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-23 23:14:10.908878 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-23 23:14:10.935933 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-23 23:14:10.938096 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.raw_variants.RData
2025-03-23 23:14:10.940776 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.filtered_variants.RData
2025-03-23 23:14:10.942717 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-23 23:14:10.944299 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-23 23:14:11.267721 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-23 23:14:11.419171 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/results/test_pe.summary_variants.tab
2025-03-23 23:14:11.422291 INFO::analyzeVariants/analyzeVariants: done
2025-03-23 23:14:11.427614 INFO::Pipeline run successful.
2025-03-23 23:14:11.635933 INFO::mergeLanes.R/doMergeLanes: starting...
2025-03-23 23:14:11.640779 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:14:11.643159 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.adapter_contaminated_1.RData
2025-03-23 23:14:11.646024 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-23 23:14:11.648116 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.adapter_contaminated_2.RData
2025-03-23 23:14:11.659635 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-23 23:14:11.662194 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.summary_preprocess.tab
2025-03-23 23:14:11.664542 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-23 23:14:11.905255 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-23 23:14:11.912079 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.summary_alignment.tab
2025-03-23 23:14:11.91964 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.summary_analyzed_bamstats.tab
2025-03-23 23:14:11.92181 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-23 23:14:12.156516 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.summary_target_lengths.tab
2025-03-23 23:14:12.205342 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-23 23:14:12.247992 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-23 23:14:12.27166 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.counts_exon.tab
2025-03-23 23:14:12.284369 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.counts_exon_disjoint.tab
2025-03-23 23:14:12.291405 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.counts_gene.tab
2025-03-23 23:14:12.297176 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.counts_gene_coding.tab
2025-03-23 23:14:12.302955 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.counts_gene_exonic.tab
2025-03-23 23:14:12.308783 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.counts_intergenic.tab
2025-03-23 23:14:12.32111 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.counts_intron.tab
2025-03-23 23:14:12.324117 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-23 23:14:12.330605 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.summary_counts.tab
2025-03-23 23:14:12.332483 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-23 23:14:12.57822 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-23 23:14:16.4131 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.coverage.RData
2025-03-23 23:14:16.420335 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.coverage.bw
2025-03-23 23:14:16.453173 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.summary_coverage.tab
2025-03-23 23:14:16.53611 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-23 23:14:16.683242 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-23 23:14:24.167588 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-23 23:14:24.394645 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-23 23:14:24.449841 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-23 23:14:24.453725 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.raw_variants.RData
2025-03-23 23:14:24.457808 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.filtered_variants.RData
2025-03-23 23:14:24.462329 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-23 23:14:24.465477 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-23 23:14:25.175832 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-23 23:14:25.474102 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.mergeLanes.170649573ec8db/merged/results/merged.summary_variants.tab
2025-03-23 23:14:25.480109 INFO::analyzeVariants/analyzeVariants: done
2025-03-23 23:14:25.486786 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:14:26.107115 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-23 23:14:26.15166 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:14:26.187006 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-23 23:14:26.192704 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:14:33.802415 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:14:33.804994 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/chunks/chunk_000001/logs/progress.log
2025-03-23 23:14:36.589846 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-03-23 23:14:36.657048 DEBUG::tools.R/processChunks: done
2025-03-23 23:14:36.659902 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:14:36.661706 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/results/test_pe.adapter_contaminated_1.RData
2025-03-23 23:14:36.66389 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-23 23:14:36.665534 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/results/test_pe.adapter_contaminated_2.RData
2025-03-23 23:14:36.674316 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-23 23:14:36.677127 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/results/test_pe.summary_preprocess.tab
2025-03-23 23:14:36.680275 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/bams/processed.aligner_input_1.fastq ...
2025-03-23 23:14:36.684773 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/bams/processed.aligner_input_2.fastq ...
2025-03-23 23:14:36.688357 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/reports/shortReadReport_1 ...
2025-03-23 23:14:38.1846 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.preprocessReads.170649548e4f22/reports/shortReadReport_2 ...
2025-03-23 23:14:39.406524 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:14:39.675209 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-23 23:14:39.681319 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:14:39.684745 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-23 23:14:39.746846 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:14:44.738792 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:14:44.740506 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/chunks/chunk_000001/logs/progress.log
2025-03-23 23:14:47.325304 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-23 23:14:47.326818 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/chunks/chunk_000002/logs/progress.log
2025-03-23 23:14:49.925207 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-03-23 23:14:49.926674 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/chunks/chunk_000003/logs/progress.log
2025-03-23 23:14:52.521742 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-03-23 23:14:52.568806 DEBUG::tools.R/processChunks: done
2025-03-23 23:14:52.571718 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:14:52.573506 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/results/test_pe.adapter_contaminated_1.RData
2025-03-23 23:14:52.575616 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-23 23:14:52.577082 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/results/test_pe.adapter_contaminated_2.RData
2025-03-23 23:14:52.585374 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-23 23:14:52.587318 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/results/test_pe.summary_preprocess.tab
2025-03-23 23:14:52.5898 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/bams/processed.aligner_input_1.fastq ...
2025-03-23 23:14:52.59395 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/bams/processed.aligner_input_2.fastq ...
2025-03-23 23:14:52.596976 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/reports/shortReadReport_1 ...
2025-03-23 23:14:53.926053 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.preprocessReads.minichunks.170649269f6134/reports/shortReadReport_2 ...
2025-03-23 23:14:55.02006 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpQNmbEr/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:14:55.289284 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-23 23:14:55.307086 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-23 23:14:55.309383 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:14:58.486059 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:14:58.487591 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpQNmbEr/test.preprocessReads_single_end.1706499815b48/chunks/chunk_000001/logs/progress.log
2025-03-23 23:15:00.845392 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2025-03-23 23:15:00.891446 DEBUG::tools.R/processChunks: done
2025-03-23 23:15:00.89451 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:15:00.896783 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads_single_end.1706499815b48/results/test_se.adapter_contaminated_1.RData
2025-03-23 23:15:00.905642 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-23 23:15:00.908171 INFO::io.R/saveWithID: saving file= /tmp/RtmpQNmbEr/test.preprocessReads_single_end.1706499815b48/results/test_se.summary_preprocess.tab
2025-03-23 23:15:00.910904 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpQNmbEr/test.preprocessReads_single_end.1706499815b48/bams/processed.aligner_input_1.fastq ...
2025-03-23 23:15:00.915183 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpQNmbEr/test.preprocessReads_single_end.1706499815b48/reports/shortReadReport_1 ...
2025-03-23 23:15:02.195973 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.readRNASeqEnds  ...  done successfully.



Executing test function test.readRNASeqEnds.dupmark  ...  done successfully.



Executing test function test.how_many  ...  done successfully.



Executing test function test.plotDF  ...  done successfully.



Executing test function test.relativeBarPlot  ...  done successfully.



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-03-23 23:15:02.819495 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-23 23:15:02.83796 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2025-03-23 23:15:02.842386 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2025-03-23 23:15:02.844811 DEBUG::tools.R/processChunks: starting...
2025-03-23 23:15:05.936627 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-23 23:15:05.938119 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-03-23 23:15:08.719824 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-03-23 23:15:08.756354 DEBUG::tools.R/processChunks: done
2025-03-23 23:15:08.75839 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-23 23:15:08.759752 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-03-23 23:15:08.761278 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-23 23:15:08.762479 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-03-23 23:15:08.767769 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2500 highqual_reads=2500 adapter_contam=0 read_length=100 rRNA_contam_reads=0 processed_reads=2500 input_min_read_length=100 input_max_read_length=100 processed_min_read_length=71 processed_max_read_length=100
2025-03-23 23:15:08.769354 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-03-23 23:15:08.771193 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-03-23 23:15:08.776087 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-03-23 23:15:08.779775 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-03-23 23:16:02.847562 DEBUG::tools.R/traceMem: wired.mem=23.549522 GiB
2025-03-23 23:17:02.913986 DEBUG::tools.R/traceMem: wired.mem=25.619313 GiB
2025-03-23 23:18:02.979008 DEBUG::tools.R/traceMem: wired.mem=24.771613 GiB
2025-03-23 23:19:03.045235 DEBUG::tools.R/traceMem: wired.mem=29.002895 GiB
2025-03-23 23:20:03.112912 DEBUG::tools.R/traceMem: wired.mem=26.311160 GiB
2025-03-23 23:21:03.178675 DEBUG::tools.R/traceMem: wired.mem=32.885101 GiB
2025-03-23 23:22:03.244368 DEBUG::tools.R/traceMem: wired.mem=40.083821 GiB
2025-03-23 23:23:03.26517 DEBUG::tools.R/traceMem: wired.mem=38.208328 GiB
2025-03-23 23:24:03.330681 DEBUG::tools.R/traceMem: wired.mem=37.914128 GiB
2025-03-23 23:25:03.396441 DEBUG::tools.R/traceMem: wired.mem=33.435259 GiB
2025-03-23 23:26:03.463394 DEBUG::tools.R/traceMem: wired.mem=34.127221 GiB
2025-03-23 23:27:03.530896 DEBUG::tools.R/traceMem: wired.mem=30.617989 GiB
2025-03-23 23:28:03.595979 DEBUG::tools.R/traceMem: wired.mem=26.487976 GiB
2025-03-23 23:29:03.663269 DEBUG::tools.R/traceMem: wired.mem=31.726113 GiB
2025-03-23 23:30:03.729336 DEBUG::tools.R/traceMem: wired.mem=36.101534 GiB
2025-03-23 23:31:03.796047 DEBUG::tools.R/traceMem: wired.mem=35.473027 GiB
2025-03-23 23:32:03.863521 DEBUG::tools.R/traceMem: wired.mem=37.454598 GiB
2025-03-23 23:33:03.929368 DEBUG::tools.R/traceMem: wired.mem=25.509573 GiB
2025-03-23 23:34:03.995664 DEBUG::tools.R/traceMem: wired.mem=26.355921 GiB
2025-03-23 23:35:04.060154 DEBUG::tools.R/traceMem: wired.mem=24.230932 GiB
2025-03-23 23:36:04.124168 DEBUG::tools.R/traceMem: wired.mem=28.830396 GiB
2025-03-23 23:37:04.16624 DEBUG::tools.R/traceMem: wired.mem=31.774069 GiB
2025-03-23 23:38:04.227349 DEBUG::tools.R/traceMem: wired.mem=32.068145 GiB
2025-03-23 23:39:04.294102 DEBUG::tools.R/traceMem: wired.mem=35.329880 GiB
2025-03-23 23:40:04.312434 DEBUG::tools.R/traceMem: wired.mem=35.419222 GiB
2025-03-23 23:41:04.378287 DEBUG::tools.R/traceMem: wired.mem=48.884109 GiB
2025-03-23 23:42:04.444067 DEBUG::tools.R/traceMem: wired.mem=41.870266 GiB
2025-03-23 23:43:04.509338 DEBUG::tools.R/traceMem: wired.mem=39.873229 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.001