Back to Multiple platform build/check report for BioC 3.22:   simplified   long
ABCDEFG[H]IJKLMNOPQRSTUVWXYZ

This page was generated on 2025-04-09 11:55 -0400 (Wed, 09 Apr 2025).

HostnameOSArch (*)R versionInstalled pkgs
nebbiolo2Linux (Ubuntu 24.04.1 LTS)x86_644.5.0 beta (2025-04-02 r88102) -- "How About a Twenty-Six" 4737
palomino8Windows Server 2022 Datacenterx644.5.0 RC (2025-04-03 r88103 ucrt) -- "How About a Twenty-Six" 4524
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

Package 998/2335HostnameOS / ArchINSTALLBUILDCHECKBUILD BIN
HTSeqGenie 4.37.1  (landing page)
Jens Reeder
Snapshot Date: 2025-04-08 13:00 -0400 (Tue, 08 Apr 2025)
git_url: https://git.bioconductor.org/packages/HTSeqGenie
git_branch: devel
git_last_commit: 3775db8
git_last_commit_date: 2024-12-17 11:20:20 -0400 (Tue, 17 Dec 2024)
nebbiolo2Linux (Ubuntu 24.04.1 LTS) / x86_64  OK    OK    TIMEOUT  
palomino8Windows Server 2022 Datacenter / x64see GPU-enabled build/check report here


CHECK results for HTSeqGenie on nebbiolo2

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.22-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.22-bioc/R/site-library --timings HTSeqGenie_4.37.1.tar.gz
StartedAt: 2025-04-08 23:19:23 -0400 (Tue, 08 Apr 2025)
EndedAt: 2025-04-08 23:59:23 -0400 (Tue, 08 Apr 2025)
EllapsedTime: 2400.7 seconds
RetCode: None
Status:   TIMEOUT  
CheckDir: HTSeqGenie.Rcheck
Warnings: NA

Command output

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


* using log directory ‘/home/biocbuild/bbs-3.22-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.5.0 beta (2025-04-02 r88102)
* 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.22-bioc/R/bin/R CMD INSTALL HTSeqGenie
###
##############################################################################
##############################################################################


* installing to library ‘/home/biocbuild/bbs-3.22-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 version 4.5.0 beta (2025-04-02 r88102) -- "How About a Twenty-Six"
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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:24:58.570279 INFO::preprocessReads.R/preprocessReads: starting...
2025-04-08 23:24:58.578925 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:24:58.582581 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-04-08 23:24:58.584841 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:25:01.391912 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:25:01.393312 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/chunks/chunk_000001/logs/progress.log
2025-04-08 23:25:04.107863 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-04-08 23:25:04.109169 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/chunks/chunk_000002/logs/progress.log
2025-04-08 23:25:06.850195 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-04-08 23:25:06.852709 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/chunks/chunk_000003/logs/progress.log
2025-04-08 23:25:09.639971 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-04-08 23:25:09.669605 DEBUG::tools.R/processChunks: done
2025-04-08 23:25:09.673306 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:25:09.675438 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/results/test_pe.adapter_contaminated_1.RData
2025-04-08 23:25:09.678028 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-04-08 23:25:09.679599 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/results/test_pe.adapter_contaminated_2.RData
2025-04-08 23:25:09.689588 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-04-08 23:25:09.692029 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/results/test_pe.summary_preprocess.tab
2025-04-08 23:25:09.69551 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/bams/processed.aligner_input_1.fastq ...
2025-04-08 23:25:09.700719 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/bams/processed.aligner_input_2.fastq ...
2025-04-08 23:25:09.705334 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/reports/shortReadReport_1 ...
2025-04-08 23:25:11.127376 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/reports/shortReadReport_2 ...
2025-04-08 23:25:13.803833 INFO::preprocessReads.R/preprocessReads: done
2025-04-08 23:25:13.892132 INFO::alignReads.R/alignReads: starting alignment...
2025-04-08 23:25:13.897989 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:25:16.854206 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:25:16.85587 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/chunks/chunk_000001/logs/progress.log
2025-04-08 23:25:19.725923 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2025-04-08 23:25:19.727561 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/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-04-08 23:25:22.34837 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-04-08 23:25:22.350636 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/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-04-08 23:25:25.007759 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-04-08 23:25:25.010289 DEBUG::tools.R/processChunks: done
2025-04-08 23:25:25.011739 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-04-08 23:25:25.232606 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-04-08 23:25:25.241271 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/results/test_pe.summary_alignment.tab
2025-04-08 23:25:25.248578 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/results/test_pe.summary_analyzed_bamstats.tab
2025-04-08 23:25:25.250317 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-04-08 23:25:25.496419 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.1831085ea3311f/results/test_pe.summary_target_lengths.tab
2025-04-08 23:25:25.544535 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-04-08 23:25:25.545715 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:25:25.796196 INFO::preprocessReads.R/preprocessReads: starting...
2025-04-08 23:25:25.79947 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:25:25.862788 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-04-08 23:25:25.867364 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:25:25.870222 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-04-08 23:25:25.872069 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:25:28.705486 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:25:28.707044 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/chunks/chunk_000001/logs/progress.log
2025-04-08 23:25:31.397007 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-04-08 23:25:31.398389 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/chunks/chunk_000002/logs/progress.log
2025-04-08 23:25:34.064968 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-04-08 23:25:34.066331 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/chunks/chunk_000003/logs/progress.log
2025-04-08 23:25:36.789242 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-04-08 23:25:36.79047 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/chunks/chunk_000004/logs/progress.log
2025-04-08 23:25:39.461292 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2025-04-08 23:25:39.495055 DEBUG::tools.R/processChunks: done
2025-04-08 23:25:39.498606 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:25:39.501062 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/results/test_pe.adapter_contaminated_1.RData
2025-04-08 23:25:39.504098 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-04-08 23:25:39.505851 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/results/test_pe.adapter_contaminated_2.RData
2025-04-08 23:25:39.516983 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-04-08 23:25:39.51939 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/results/test_pe.summary_preprocess.tab
2025-04-08 23:25:39.52318 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/bams/processed.aligner_input_1.fastq ...
2025-04-08 23:25:39.528201 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/bams/processed.aligner_input_2.fastq ...
2025-04-08 23:25:39.531986 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/reports/shortReadReport_1 ...
2025-04-08 23:25:40.893829 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.alignReads.sparsechunks.18310857b2f14d/reports/shortReadReport_2 ...
2025-04-08 23:25:43.826652 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:25:44.019556 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-04-08 23:25:44.023761 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/RtmpVP3W5X/test.alignReadsOneSingleEnd.18310855a266f7/bams/test.alignReads /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-04-08 23:25:44.222896 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-04-08 23:25:44.309638 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReadsOneSingleEnd.18310855a266f7/results/test.alignReads.summary_alignment.tab
2025-04-08 23:25:44.360296 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.alignReadsOneSingleEnd.18310855a266f7/results/test.alignReads.summary_analyzed_bamstats.tab
2025-04-08 23:25:44.361894 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.002 0 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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:25:44.646621 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.genotype.183108afc7c03/results/test_pe.coverage.RData
2025-04-08 23:25:44.648416 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpVP3W5X/test.genotype.183108afc7c03/results/test_pe.coverage.bw
2025-04-08 23:25:44.752513 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.genotype.183108afc7c03/results/test_pe.summary_coverage.tab
2025-04-08 23:25:44.75404 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-04-08 23:25:55.188839 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-04-08 23:25:55.301188 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-04-08 23:25:55.322852 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-04-08 23:25:55.324701 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.genotype.183108afc7c03/results/test_pe.raw_variants.RData
2025-04-08 23:25:55.327565 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.genotype.183108afc7c03/results/test_pe.filtered_variants.RData
2025-04-08 23:25:55.32931 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-04-08 23:25:55.330858 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-04-08 23:25:55.845484 INFO::analyzeVariants.R/writeVCF: ...done
2025-04-08 23:25:55.846895 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-04-08 23:26:56.727287 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-04-08 23:26:57.10572 INFO::analyzeVariants.R/writeVCF: ...done
2025-04-08 23:26:57.106632 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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:26:57.513224 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-04-08 23:27:07.123099 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-04-08 23:27:07.204038 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-04-08 23:27:07.222073 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-04-08 23:27:07.223473 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.183108b8d90f/results/test_pe.raw_variants.RData
2025-04-08 23:27:07.225867 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.183108b8d90f/results/test_pe.filtered_variants.RData
2025-04-08 23:27:07.227275 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:27:07.382949 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-04-08 23:27:17.193841 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-04-08 23:27:17.267292 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-04-08 23:27:17.286068 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-04-08 23:27:17.287636 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.filters.18310835168c08/results/test_pe.raw_variants.RData
2025-04-08 23:27:17.290148 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.filters.18310835168c08/results/test_pe.filtered_variants.RData
2025-04-08 23:27:17.291471 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-04-08 23:27:17.293056 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-04-08 23:27:26.959977 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-04-08 23:27:27.001165 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-04-08 23:27:27.018938 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-04-08 23:27:27.020334 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.filters.18310835168c08/results/test_pe.raw_variants.RData
2025-04-08 23:27:27.022983 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.filters.18310835168c08/results/test_pe.filtered_variants.RData
2025-04-08 23:27:27.025011 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:27:27.280435 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-04-08 23:27:27.282325 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-04-08 23:27:30.070064 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-04-08 23:27:30.146185 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-04-08 23:27:30.163052 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-04-08 23:27:30.164401 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.which.1831087a4b97d5/results/test_pe.raw_variants.RData
2025-04-08 23:27:30.166027 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.wrap.callVariants.which.1831087a4b97d5/results/test_pe.filtered_variants.RData
2025-04-08 23:27:30.1673 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:27:30.299374 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-04-08 23:27:30.300663 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:27:30.462317 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-04-08 23:27:30.681652 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-04-08 23:28:22.456227 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/pbnqojkz/merged/results/bla.coverage.RData
2025-04-08 23:28:22.459139 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpVP3W5X/pbnqojkz/merged/results/bla.coverage.bw
2025-04-08 23:28:22.536882 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/pbnqojkz/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-04-08 23:28:23.612173 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/wastqbon/merged/results/bla.coverage.RData
2025-04-08 23:28:23.613764 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpVP3W5X/wastqbon/merged/results/bla.coverage.bw
2025-04-08 23:28:23.625393 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/wastqbon/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:24.774506 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-04-08 23:28:24.775532 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpVP3W5X/test.detectRRNA.183108576aeee/bams/rRNA_contam/input1.fastq
2025-04-08 23:28:24.77857 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/RtmpVP3W5X/test.detectRRNA.183108576aeee/bams/rRNA_contam/test_se /tmp/RtmpVP3W5X/test.detectRRNA.183108576aeee/bams/rRNA_contam/input1.fastq 2>&1
2025-04-08 23:28:24.916667 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-04-08 23:28:24.917661 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:25.067138 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-04-08 23:28:25.068119 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpVP3W5X/test.detectRRNA.paired_end.18310877e2bf96/bams/rRNA_contam/input1.fastq
2025-04-08 23:28:25.069602 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpVP3W5X/test.detectRRNA.paired_end.18310877e2bf96/bams/rRNA_contam/input2.fastq
2025-04-08 23:28:25.071797 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/RtmpVP3W5X/test.detectRRNA.paired_end.18310877e2bf96/bams/rRNA_contam/test_pe /tmp/RtmpVP3W5X/test.detectRRNA.paired_end.18310877e2bf96/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpVP3W5X/test.detectRRNA.paired_end.18310877e2bf96/bams/rRNA_contam/input2.fastq 2>&1
2025-04-08 23:28:25.310972 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-04-08 23:28:25.312068 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-04-08 23:28:25.331554 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/RtmpVP3W5X/test_get_rRNA_idseqroplsy/test_pe /tmp/RtmpVP3W5X/test_get_rRNA_idseqroplsy/1.fastq -a paired /tmp/RtmpVP3W5X/test_get_rRNA_idseqroplsy/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-04-08 23:28:25.582293 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/RtmpVP3W5X/test_get_rRNAIds_randomnqsrmzue/test_pe /tmp/RtmpVP3W5X/test_get_rRNAIds_randomnqsrmzue/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-04-08 23:28:25.788623 INFO::filterQuality.R/filterQuality: filterByLength...
2025-04-08 23:28:25.790041 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-04-08 23:28:25.790877 INFO::filterQuality.R/filterByLength: done
2025-04-08 23:28:25.836555 INFO::filterQuality.R/filterQuality: filterByLength...
2025-04-08 23:28:25.837442 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-04-08 23:28:25.838217 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-04-08 23:28:25.887429 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-04-08 23:28:25.896189 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-04-08 23:28:25.897259 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-04-08 23:28:25.901664 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-04-08 23:28:25.90261 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-04-08 23:28:25.906955 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-04-08 23:28:25.907863 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-04-08 23:28:25.912158 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.001 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.001 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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:26.167964 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:26.170068 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:26.338463 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:26.405457 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-04-08 23:28:26.408131 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:26.410193 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:26.599518 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:26.74405 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:26.878196 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:26.923693 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-04-08 23:28:26.926161 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:26.928375 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:27.130234 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:27.144988 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-04-08 23:28:27.147358 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:27.14948 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-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/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:28:27.872391 INFO::preprocessReads.R/preprocessReads: starting...
2025-04-08 23:28:27.878196 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:28:27.881527 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-04-08 23:28:27.883694 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:28:30.65001 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:28:30.651399 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000001/logs/progress.log
2025-04-08 23:28:33.283287 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-04-08 23:28:33.284811 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000002/logs/progress.log
2025-04-08 23:28:35.866312 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-04-08 23:28:35.867678 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000003/logs/progress.log
2025-04-08 23:28:38.486399 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-04-08 23:28:38.526237 DEBUG::tools.R/processChunks: done
2025-04-08 23:28:38.528856 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:28:38.530398 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.adapter_contaminated_1.RData
2025-04-08 23:28:38.532329 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-04-08 23:28:38.533709 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.adapter_contaminated_2.RData
2025-04-08 23:28:38.54128 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-04-08 23:28:38.542991 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.summary_preprocess.tab
2025-04-08 23:28:38.54529 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/bams/processed.aligner_input_1.fastq ...
2025-04-08 23:28:38.549865 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/bams/processed.aligner_input_2.fastq ...
2025-04-08 23:28:38.553165 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/reports/shortReadReport_1 ...
2025-04-08 23:28:39.820303 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/reports/shortReadReport_2 ...
2025-04-08 23:28:40.829164 INFO::preprocessReads.R/preprocessReads: done
2025-04-08 23:28:40.946307 INFO::alignReads.R/alignReads: starting alignment...
2025-04-08 23:28:40.950691 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:28:44.165019 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:28:44.166765 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000001/logs/progress.log
2025-04-08 23:28:46.737907 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-04-08 23:28:46.740304 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/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-04-08 23:28:49.355031 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-04-08 23:28:49.357769 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/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-04-08 23:28:51.974458 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-04-08 23:28:51.978207 DEBUG::tools.R/processChunks: done
2025-04-08 23:28:51.980422 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-04-08 23:28:52.236125 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-04-08 23:28:52.24385 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.summary_alignment.tab
2025-04-08 23:28:52.250806 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.summary_analyzed_bamstats.tab
2025-04-08 23:28:52.252687 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-04-08 23:28:52.495971 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.summary_target_lengths.tab
2025-04-08 23:28:52.543538 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-04-08 23:28:52.544685 INFO::alignReads.R/alignReads: done
2025-04-08 23:28:52.68061 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-04-08 23:28:52.701253 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:28:55.510311 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:28:55.511895 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000001/logs/progress.log
2025-04-08 23:28:57.977476 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2025-04-08 23:28:57.979053 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000002/logs/progress.log
2025-04-08 23:29:00.418054 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2025-04-08 23:29:00.419528 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000003/logs/progress.log
2025-04-08 23:29:02.876466 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2025-04-08 23:29:02.880066 DEBUG::tools.R/processChunks: done
2025-04-08 23:29:02.882436 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-04-08 23:29:02.898241 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.counts_exon.tab
2025-04-08 23:29:02.909559 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.counts_exon_disjoint.tab
2025-04-08 23:29:02.916461 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.counts_gene.tab
2025-04-08 23:29:02.921879 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.counts_gene_coding.tab
2025-04-08 23:29:02.927098 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.counts_gene_exonic.tab
2025-04-08 23:29:02.932419 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.counts_intergenic.tab
2025-04-08 23:29:02.941447 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.counts_intron.tab
2025-04-08 23:29:02.943974 INFO::countGenomicFeatures.R/mergeCounts: done
2025-04-08 23:29:02.949291 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.summary_counts.tab
2025-04-08 23:29:02.950794 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-04-08 23:29:03.249131 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-04-08 23:29:03.250061 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-04-08 23:29:03.373358 INFO::coverage.R/calculateCoverage: starting...
2025-04-08 23:29:03.377543 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:29:06.376199 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:29:06.37794 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000001/logs/progress.log
2025-04-08 23:29:08.558681 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2025-04-08 23:29:08.560463 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000002/logs/progress.log
2025-04-08 23:29:10.982937 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2025-04-08 23:29:10.98462 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/chunks/chunk_000003/logs/progress.log
2025-04-08 23:29:13.506341 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2025-04-08 23:29:13.51896 DEBUG::tools.R/processChunks: done
2025-04-08 23:29:17.816639 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.coverage.RData
2025-04-08 23:29:17.819758 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.coverage.bw
2025-04-08 23:29:17.845456 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.summary_coverage.tab
2025-04-08 23:29:17.848394 INFO::coverage.R/calculateCoverage: done
2025-04-08 23:29:17.852422 INFO::analyzeVariants/analyzeVariants: starting ...
2025-04-08 23:29:18.359147 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-04-08 23:29:25.848693 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-04-08 23:29:26.011074 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-04-08 23:29:26.050508 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-04-08 23:29:26.053941 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.raw_variants.RData
2025-04-08 23:29:26.057563 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.filtered_variants.RData
2025-04-08 23:29:26.060372 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-04-08 23:29:26.062361 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-04-08 23:29:26.660078 INFO::analyzeVariants.R/writeVCF: ...done
2025-04-08 23:29:26.892366 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/results/test_pe.summary_variants.tab
2025-04-08 23:29:26.896446 INFO::analyzeVariants/analyzeVariants: done
2025-04-08 23:29:26.905611 INFO::Pipeline run successful.
2025-04-08 23:29:27.420767 INFO::mergeLanes.R/doMergeLanes: starting...
2025-04-08 23:29:27.441001 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:29:27.445367 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.adapter_contaminated_1.RData
2025-04-08 23:29:27.455555 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-04-08 23:29:27.468463 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.adapter_contaminated_2.RData
2025-04-08 23:29:27.520408 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-04-08 23:29:27.529401 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.summary_preprocess.tab
2025-04-08 23:29:27.542688 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-04-08 23:29:28.253714 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-04-08 23:29:28.272037 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.summary_alignment.tab
2025-04-08 23:29:28.305959 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.summary_analyzed_bamstats.tab
2025-04-08 23:29:28.314595 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-04-08 23:29:28.840177 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.summary_target_lengths.tab
2025-04-08 23:29:28.922046 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-04-08 23:29:29.067087 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-04-08 23:29:29.116038 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.counts_exon.tab
2025-04-08 23:29:29.14579 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.counts_exon_disjoint.tab
2025-04-08 23:29:29.161398 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.counts_gene.tab
2025-04-08 23:29:29.174823 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.counts_gene_coding.tab
2025-04-08 23:29:29.186777 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.counts_gene_exonic.tab
2025-04-08 23:29:29.199471 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.counts_intergenic.tab
2025-04-08 23:29:29.22649 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.counts_intron.tab
2025-04-08 23:29:29.232496 INFO::countGenomicFeatures.R/mergeCounts: done
2025-04-08 23:29:29.245133 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.summary_counts.tab
2025-04-08 23:29:29.248961 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-04-08 23:29:29.667318 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-04-08 23:29:34.192061 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.coverage.RData
2025-04-08 23:29:34.195713 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.coverage.bw
2025-04-08 23:29:34.210629 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.summary_coverage.tab
2025-04-08 23:29:34.29375 INFO::analyzeVariants/analyzeVariants: starting ...
2025-04-08 23:29:34.387219 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-04-08 23:29:37.768893 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-04-08 23:29:37.862955 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-04-08 23:29:37.884793 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-04-08 23:29:37.886753 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.raw_variants.RData
2025-04-08 23:29:37.888985 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.filtered_variants.RData
2025-04-08 23:29:37.890693 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-04-08 23:29:37.89195 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-04-08 23:29:38.189754 INFO::analyzeVariants.R/writeVCF: ...done
2025-04-08 23:29:38.339103 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.mergeLanes.1831086f4128d8/merged/results/merged.summary_variants.tab
2025-04-08 23:29:38.34235 INFO::analyzeVariants/analyzeVariants: done
2025-04-08 23:29:38.347809 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:29:39.009363 INFO::preprocessReads.R/preprocessReads: starting...
2025-04-08 23:29:39.039991 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:29:39.069803 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-04-08 23:29:39.07576 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:29:45.643011 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:29:45.646612 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/chunks/chunk_000001/logs/progress.log
2025-04-08 23:29:48.748372 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2025-04-08 23:29:48.831134 DEBUG::tools.R/processChunks: done
2025-04-08 23:29:48.835529 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:29:48.838305 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/results/test_pe.adapter_contaminated_1.RData
2025-04-08 23:29:48.84128 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-04-08 23:29:48.843774 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/results/test_pe.adapter_contaminated_2.RData
2025-04-08 23:29:48.856414 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-04-08 23:29:48.859697 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/results/test_pe.summary_preprocess.tab
2025-04-08 23:29:48.863361 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/bams/processed.aligner_input_1.fastq ...
2025-04-08 23:29:48.871189 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/bams/processed.aligner_input_2.fastq ...
2025-04-08 23:29:48.878221 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/reports/shortReadReport_1 ...
2025-04-08 23:29:51.127496 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.preprocessReads.18310879c06658/reports/shortReadReport_2 ...
2025-04-08 23:29:52.3974 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:29:52.918883 INFO::preprocessReads.R/preprocessReads: starting...
2025-04-08 23:29:52.930085 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:29:52.940375 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-04-08 23:29:52.946333 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:29:57.391805 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:29:57.393589 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/chunks/chunk_000001/logs/progress.log
2025-04-08 23:30:00.022326 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-04-08 23:30:00.024487 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/chunks/chunk_000002/logs/progress.log
2025-04-08 23:30:02.696456 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-04-08 23:30:02.698015 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/chunks/chunk_000003/logs/progress.log
2025-04-08 23:30:05.314329 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-04-08 23:30:05.389733 DEBUG::tools.R/processChunks: done
2025-04-08 23:30:05.393883 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:30:05.39649 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/results/test_pe.adapter_contaminated_1.RData
2025-04-08 23:30:05.399698 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-04-08 23:30:05.402109 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/results/test_pe.adapter_contaminated_2.RData
2025-04-08 23:30:05.414 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-04-08 23:30:05.416719 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/results/test_pe.summary_preprocess.tab
2025-04-08 23:30:05.420364 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/bams/processed.aligner_input_1.fastq ...
2025-04-08 23:30:05.425916 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/bams/processed.aligner_input_2.fastq ...
2025-04-08 23:30:05.430951 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/reports/shortReadReport_1 ...
2025-04-08 23:30:06.76352 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.preprocessReads.minichunks.18310820f8cab0/reports/shortReadReport_2 ...
2025-04-08 23:30:08.122403 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpVP3W5X/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:30:08.386187 INFO::preprocessReads.R/preprocessReads: starting...
2025-04-08 23:30:08.406635 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-04-08 23:30:08.409259 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:30:11.972498 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:30:11.974026 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpVP3W5X/test.preprocessReads_single_end.1831087c24e6c5/chunks/chunk_000001/logs/progress.log
2025-04-08 23:30:14.341775 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2025-04-08 23:30:14.376143 DEBUG::tools.R/processChunks: done
2025-04-08 23:30:14.378291 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:30:14.379731 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads_single_end.1831087c24e6c5/results/test_se.adapter_contaminated_1.RData
2025-04-08 23:30:14.385497 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-04-08 23:30:14.387019 INFO::io.R/saveWithID: saving file= /tmp/RtmpVP3W5X/test.preprocessReads_single_end.1831087c24e6c5/results/test_se.summary_preprocess.tab
2025-04-08 23:30:14.388689 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpVP3W5X/test.preprocessReads_single_end.1831087c24e6c5/bams/processed.aligner_input_1.fastq ...
2025-04-08 23:30:14.392306 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpVP3W5X/test.preprocessReads_single_end.1831087c24e6c5/reports/shortReadReport_1 ...
2025-04-08 23:30:15.668645 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.22-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-04-08 23:30:16.315473 INFO::preprocessReads.R/preprocessReads: starting...
2025-04-08 23:30:16.336307 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2025-04-08 23:30:16.353014 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.22-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2025-04-08 23:30:16.355474 DEBUG::tools.R/processChunks: starting...
2025-04-08 23:30:19.497464 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-04-08 23:30:19.498993 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-04-08 23:30:22.294679 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2025-04-08 23:30:22.329391 DEBUG::tools.R/processChunks: done
2025-04-08 23:30:22.331334 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-04-08 23:30:22.332591 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-04-08 23:30:22.33399 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-04-08 23:30:22.335145 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-04-08 23:30:22.34039 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-04-08 23:30:22.341911 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-04-08 23:30:22.343631 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-04-08 23:30:22.348228 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-04-08 23:30:22.351595 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-04-08 23:31:16.325794 DEBUG::tools.R/traceMem: wired.mem=-80.874942 GiB
2025-04-08 23:32:16.390811 DEBUG::tools.R/traceMem: wired.mem=-82.611425 GiB
2025-04-08 23:33:16.456194 DEBUG::tools.R/traceMem: wired.mem=-72.639681 GiB
2025-04-08 23:34:16.523099 DEBUG::tools.R/traceMem: wired.mem=-74.056757 GiB
2025-04-08 23:35:16.589741 DEBUG::tools.R/traceMem: wired.mem=-75.581002 GiB
2025-04-08 23:36:16.65487 DEBUG::tools.R/traceMem: wired.mem=-76.363215 GiB
2025-04-08 23:37:16.72008 DEBUG::tools.R/traceMem: wired.mem=-72.190947 GiB
2025-04-08 23:38:16.784742 DEBUG::tools.R/traceMem: wired.mem=-68.521808 GiB
2025-04-08 23:39:16.849692 DEBUG::tools.R/traceMem: wired.mem=-70.002168 GiB
2025-04-08 23:40:16.91551 DEBUG::tools.R/traceMem: wired.mem=-74.883838 GiB
2025-04-08 23:41:16.982508 DEBUG::tools.R/traceMem: wired.mem=-72.280347 GiB
2025-04-08 23:42:17.04838 DEBUG::tools.R/traceMem: wired.mem=-80.320221 GiB
2025-04-08 23:43:17.114763 DEBUG::tools.R/traceMem: wired.mem=-83.096195 GiB
2025-04-08 23:44:17.17897 DEBUG::tools.R/traceMem: wired.mem=-70.307754 GiB
2025-04-08 23:45:17.24486 DEBUG::tools.R/traceMem: wired.mem=-77.781283 GiB
2025-04-08 23:46:17.309672 DEBUG::tools.R/traceMem: wired.mem=-76.863615 GiB
2025-04-08 23:47:17.374894 DEBUG::tools.R/traceMem: wired.mem=-73.790288 GiB
2025-04-08 23:48:17.439234 DEBUG::tools.R/traceMem: wired.mem=-78.586057 GiB
2025-04-08 23:49:17.505622 DEBUG::tools.R/traceMem: wired.mem=-75.044090 GiB
2025-04-08 23:50:17.571209 DEBUG::tools.R/traceMem: wired.mem=-84.292956 GiB
2025-04-08 23:51:17.636229 DEBUG::tools.R/traceMem: wired.mem=-77.416886 GiB
2025-04-08 23:52:17.703077 DEBUG::tools.R/traceMem: wired.mem=-71.659467 GiB
2025-04-08 23:53:17.768157 DEBUG::tools.R/traceMem: wired.mem=-78.193463 GiB
2025-04-08 23:54:17.834935 DEBUG::tools.R/traceMem: wired.mem=-76.735730 GiB
2025-04-08 23:55:17.841358 DEBUG::tools.R/traceMem: wired.mem=-73.978892 GiB
2025-04-08 23:56:17.909667 DEBUG::tools.R/traceMem: wired.mem=-71.946039 GiB
2025-04-08 23:57:17.975643 DEBUG::tools.R/traceMem: wired.mem=-64.050418 GiB
2025-04-08 23:58:18.043939 DEBUG::tools.R/traceMem: wired.mem=-75.863871 GiB
2025-04-08 23:59:18.110965 DEBUG::tools.R/traceMem: wired.mem=-77.168964 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

nameusersystemelapsed
HTSeqGenie000
buildGenomicFeaturesFromTxDb0.0000.0000.001
runPipeline000