Multiple platform build/check report for BioC 3.20 - CHECK results for HTSeqGenie on nebbiolo2

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo2	Linux (Ubuntu 24.04.1 LTS)	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4746
palomino8	Windows Server 2022 Datacenter	x64	4.4.2 (2024-10-31 ucrt) -- "Pile of Leaves"	4494
merida1	macOS 12.7.5 Monterey	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4517
kjohnson1	macOS 13.6.6 Ventura	arm64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4469
taishan	Linux (openEuler 24.03 LTS)	aarch64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4400
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 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.36.0

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

StartedAt: 2025-01-30 23:05:11 -0500 (Thu, 30 Jan 2025)

EndedAt: 2025-01-30 23:45:12 -0500 (Thu, 30 Jan 2025)

EllapsedTime: 2400.9 seconds

RetCode: None

Status: TIMEOUT

CheckDir: HTSeqGenie.Rcheck

Warnings: NA

Command output

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


* using log directory ‘/home/biocbuild/bbs-3.20-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.4.2 (2024-10-31)
* using platform: x86_64-pc-linux-gnu
* R was compiled by
    gcc (Ubuntu 13.2.0-23ubuntu4) 13.2.0
    GNU Fortran (Ubuntu 13.2.0-23ubuntu4) 13.2.0
* running under: Ubuntu 24.04.1 LTS
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.36.0’
* 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.20-bioc/R/bin/R CMD INSTALL HTSeqGenie
###
##############################################################################
##############################################################################


* installing to library ‘/home/biocbuild/bbs-3.20-bioc/R/site-library’
* installing *source* package ‘HTSeqGenie’ ...
** using staged installation
** R
** inst
** byte-compile and prepare package for lazy loading
** help
*** installing help indices
** building package indices
** installing vignettes
** testing if installed package can be loaded from temporary location
** testing if installed package can be loaded from final location
** testing if installed package keeps a record of temporary installation path
* DONE (HTSeqGenie)

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.4.2 (2024-10-31) -- "Pile of Leaves"
Copyright (C) 2024 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu

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

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

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

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

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, intersect, is.unsorted,
    lapply, mapply, match, mget, order, paste, pmax, pmax.int, pmin,
    pmin.int, rank, rbind, rownames, sapply, saveRDS, setdiff, table,
    tapply, union, 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

> 
> 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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:10:43.456307 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-30 23:10:43.465371 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:10:43.469232 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-30 23:10:43.471555 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:10:46.787447 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:10:46.789826 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/chunks/chunk_000001/logs/progress.log
2025-01-30 23:10:49.558253 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-01-30 23:10:49.5605 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/chunks/chunk_000002/logs/progress.log
2025-01-30 23:10:52.338018 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-01-30 23:10:52.339435 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/chunks/chunk_000003/logs/progress.log
2025-01-30 23:10:55.08346 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-01-30 23:10:55.116413 DEBUG::tools.R/processChunks: done
2025-01-30 23:10:55.120611 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:10:55.122894 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/results/test_pe.adapter_contaminated_1.RData
2025-01-30 23:10:55.125615 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-30 23:10:55.127243 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/results/test_pe.adapter_contaminated_2.RData
2025-01-30 23:10:55.136412 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-30 23:10:55.138827 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/results/test_pe.summary_preprocess.tab
2025-01-30 23:10:55.14234 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/bams/processed.aligner_input_1.fastq ...
2025-01-30 23:10:55.147295 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/bams/processed.aligner_input_2.fastq ...
2025-01-30 23:10:55.15097 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/reports/shortReadReport_1 ...
2025-01-30 23:10:56.544219 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/reports/shortReadReport_2 ...
2025-01-30 23:10:57.694917 INFO::preprocessReads.R/preprocessReads: done
2025-01-30 23:10:57.780503 INFO::alignReads.R/alignReads: starting alignment...
2025-01-30 23:10:57.786987 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:11:00.989134 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:11:00.990866 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/chunks/chunk_000001/logs/progress.log
2025-01-30 23:11:03.919835 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2025-01-30 23:11:03.921722 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-30 23:11:06.600618 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-01-30 23:11:06.602307 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-30 23:11:09.250441 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-01-30 23:11:09.253504 DEBUG::tools.R/processChunks: done
2025-01-30 23:11:09.255326 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-30 23:11:09.478282 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-30 23:11:09.486398 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/results/test_pe.summary_alignment.tab
2025-01-30 23:11:09.493268 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/results/test_pe.summary_analyzed_bamstats.tab
2025-01-30 23:11:09.494873 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-30 23:11:09.731452 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.28e33827ac1a9f/results/test_pe.summary_target_lengths.tab
2025-01-30 23:11:09.777899 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-30 23:11:09.778936 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:11:10.088688 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-30 23:11:10.092418 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:11:10.167343 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-01-30 23:11:10.172358 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:11:10.17545 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-30 23:11:10.177517 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:11:13.226763 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:11:13.22817 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/chunks/chunk_000001/logs/progress.log
2025-01-30 23:11:15.951191 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-01-30 23:11:15.952777 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/chunks/chunk_000002/logs/progress.log
2025-01-30 23:11:18.672334 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-01-30 23:11:18.674359 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/chunks/chunk_000003/logs/progress.log
2025-01-30 23:11:21.442376 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-01-30 23:11:21.444617 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/chunks/chunk_000004/logs/progress.log
2025-01-30 23:11:24.102719 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2025-01-30 23:11:24.128128 DEBUG::tools.R/processChunks: done
2025-01-30 23:11:24.131175 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:11:24.133282 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/results/test_pe.adapter_contaminated_1.RData
2025-01-30 23:11:24.135973 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-30 23:11:24.137613 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/results/test_pe.adapter_contaminated_2.RData
2025-01-30 23:11:24.146949 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-30 23:11:24.148949 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/results/test_pe.summary_preprocess.tab
2025-01-30 23:11:24.152062 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/bams/processed.aligner_input_1.fastq ...
2025-01-30 23:11:24.156097 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/bams/processed.aligner_input_2.fastq ...
2025-01-30 23:11:24.158984 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/reports/shortReadReport_1 ...
2025-01-30 23:11:25.44918 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReads.sparsechunks.28e33858611876/reports/shortReadReport_2 ...
2025-01-30 23:11:26.507556 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:11:26.689884 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-01-30 23:11:26.694533 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 /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReadsOneSingleEnd.28e33848ea6026/bams/test.alignReads /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-01-30 23:11:26.906198 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-01-30 23:11:27.010693 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReadsOneSingleEnd.28e33848ea6026/results/test.alignReads.summary_alignment.tab
2025-01-30 23:11:27.055178 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.alignReadsOneSingleEnd.28e33848ea6026/results/test.alignReads.summary_analyzed_bamstats.tab
2025-01-30 23:11:27.05672 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:11:27.371202 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.genotype.28e3387ec28966/results/test_pe.coverage.RData
2025-01-30 23:11:27.373155 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.genotype.28e3387ec28966/results/test_pe.coverage.bw
2025-01-30 23:11:27.494891 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.genotype.28e3387ec28966/results/test_pe.summary_coverage.tab
2025-01-30 23:11:27.496636 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-30 23:11:38.236736 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-30 23:11:38.36551 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-30 23:11:38.388835 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-30 23:11:38.390676 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.genotype.28e3387ec28966/results/test_pe.raw_variants.RData
2025-01-30 23:11:38.393591 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.genotype.28e3387ec28966/results/test_pe.filtered_variants.RData
2025-01-30 23:11:38.395269 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-30 23:11:38.396719 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-30 23:11:38.884149 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-30 23:11:38.88539 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-01-30 23:12:38.146231 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-30 23:12:38.596136 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-30 23:12:38.597172 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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:12:39.048028 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-30 23:12:50.021857 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-30 23:12:50.102383 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-30 23:12:50.119318 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-30 23:12:50.120713 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.28e338155fc73/results/test_pe.raw_variants.RData
2025-01-30 23:12:50.123177 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.28e338155fc73/results/test_pe.filtered_variants.RData
2025-01-30 23:12:50.12451 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:12:50.268253 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-30 23:13:01.185921 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-30 23:13:01.246624 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-30 23:13:01.264159 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-30 23:13:01.265692 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.filters.28e33849252e4f/results/test_pe.raw_variants.RData
2025-01-30 23:13:01.268194 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.filters.28e33849252e4f/results/test_pe.filtered_variants.RData
2025-01-30 23:13:01.269552 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-30 23:13:01.271117 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-30 23:13:11.636832 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-30 23:13:11.692839 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-30 23:13:11.714814 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-30 23:13:11.716657 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.filters.28e33849252e4f/results/test_pe.raw_variants.RData
2025-01-30 23:13:11.719746 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.filters.28e33849252e4f/results/test_pe.filtered_variants.RData
2025-01-30 23:13:11.722128 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:13:12.084904 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-30 23:13:12.086629 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-01-30 23:13:15.364399 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-30 23:13:15.446252 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-30 23:13:15.483374 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-30 23:13:15.485264 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.which.28e3384574c8ca/results/test_pe.raw_variants.RData
2025-01-30 23:13:15.487312 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.wrap.callVariants.which.28e3384574c8ca/results/test_pe.filtered_variants.RData
2025-01-30 23:13:15.488921 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:13:15.691207 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-30 23:13:15.692899 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:13:17.455364 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-30 23:13:17.673012 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



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



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



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



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



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



Executing test function test.mergeCoverage  ... 2025-01-30 23:14:11.775105 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/kfytjeci/merged/results/bla.coverage.RData
2025-01-30 23:14:11.780048 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/kfytjeci/merged/results/bla.coverage.bw
2025-01-30 23:14:11.877112 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/kfytjeci/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-01-30 23:14:13.227918 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/turclbmd/merged/results/bla.coverage.RData
2025-01-30 23:14:13.22954 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/turclbmd/merged/results/bla.coverage.bw
2025-01-30 23:14:13.241564 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/turclbmd/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:14.494916 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-01-30 23:14:14.49606 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.28e3387e79af54/bams/rRNA_contam/input1.fastq
2025-01-30 23:14:14.499382 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 /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.28e3387e79af54/bams/rRNA_contam/test_se /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.28e3387e79af54/bams/rRNA_contam/input1.fastq 2>&1
2025-01-30 23:14:14.645244 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-01-30 23:14:14.646293 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:14.764842 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-01-30 23:14:14.765839 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.paired_end.28e33863116c2c/bams/rRNA_contam/input1.fastq
2025-01-30 23:14:14.767307 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.paired_end.28e33863116c2c/bams/rRNA_contam/input2.fastq
2025-01-30 23:14:14.76942 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 /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.paired_end.28e33863116c2c/bams/rRNA_contam/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.paired_end.28e33863116c2c/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.detectRRNA.paired_end.28e33863116c2c/bams/rRNA_contam/input2.fastq 2>&1
2025-01-30 23:14:15.002584 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-01-30 23:14:15.003644 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-01-30 23:14:15.023052 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 /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test_get_rRNA_idsbxertdla/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test_get_rRNA_idsbxertdla/1.fastq -a paired /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test_get_rRNA_idsbxertdla/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-01-30 23:14:15.320632 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 /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test_get_rRNAIds_randomdzisgtqr/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test_get_rRNAIds_randomdzisgtqr/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-01-30 23:14:15.541369 INFO::filterQuality.R/filterQuality: filterByLength...
2025-01-30 23:14:15.542995 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-01-30 23:14:15.543937 INFO::filterQuality.R/filterByLength: done
2025-01-30 23:14:15.590384 INFO::filterQuality.R/filterQuality: filterByLength...
2025-01-30 23:14:15.591334 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-01-30 23:14:15.592151 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-01-30 23:14:15.643104 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-30 23:14:15.65262 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-30 23:14:15.6538 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-30 23:14:15.658635 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-30 23:14:15.659739 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-30 23:14:15.664397 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-30 23:14:15.665421 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-30 23:14:15.67007 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.001 0 0
Error in DEACTIVATED("callVariantsGATK() tests need gatk.path option set") : 
  callVariantsGATK() tests need gatk.path option set
 done successfully.



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



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



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



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



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



Executing test function test.realignIndelsGATK.parallel  ... Timing stopped at: 0 0 0.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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:15.930297 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:15.932775 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:16.106604 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:16.177493 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-30 23:14:16.180388 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:16.182633 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:16.375087 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:16.510308 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:16.640917 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:16.686805 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-30 23:14:16.689146 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:16.691229 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:16.869128 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:16.916273 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-30 23:14:16.918651 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:16.920811 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:14:17.585413 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-30 23:14:17.591682 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:14:17.595248 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-30 23:14:17.597614 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:14:20.567876 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:14:20.5693 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000001/logs/progress.log
2025-01-30 23:14:23.133079 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-01-30 23:14:23.134456 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000002/logs/progress.log
2025-01-30 23:14:25.74589 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-01-30 23:14:25.747391 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000003/logs/progress.log
2025-01-30 23:14:28.374068 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-01-30 23:14:28.420984 DEBUG::tools.R/processChunks: done
2025-01-30 23:14:28.423601 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:14:28.425211 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.adapter_contaminated_1.RData
2025-01-30 23:14:28.427247 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-30 23:14:28.42869 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.adapter_contaminated_2.RData
2025-01-30 23:14:28.436543 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-30 23:14:28.438228 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.summary_preprocess.tab
2025-01-30 23:14:28.44052 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/bams/processed.aligner_input_1.fastq ...
2025-01-30 23:14:28.444462 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/bams/processed.aligner_input_2.fastq ...
2025-01-30 23:14:28.448123 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/reports/shortReadReport_1 ...
2025-01-30 23:14:29.738422 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/reports/shortReadReport_2 ...
2025-01-30 23:14:30.770889 INFO::preprocessReads.R/preprocessReads: done
2025-01-30 23:14:30.929363 INFO::alignReads.R/alignReads: starting alignment...
2025-01-30 23:14:30.934511 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:14:34.11369 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:14:34.116216 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000001/logs/progress.log
2025-01-30 23:14:36.702878 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-01-30 23:14:36.704442 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-30 23:14:39.311327 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-01-30 23:14:39.312945 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-30 23:14:41.872922 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-01-30 23:14:41.875019 DEBUG::tools.R/processChunks: done
2025-01-30 23:14:41.876254 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-30 23:14:42.070643 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-30 23:14:42.077754 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.summary_alignment.tab
2025-01-30 23:14:42.084037 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.summary_analyzed_bamstats.tab
2025-01-30 23:14:42.085738 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-30 23:14:42.303589 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.summary_target_lengths.tab
2025-01-30 23:14:42.34825 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-30 23:14:42.349205 INFO::alignReads.R/alignReads: done
2025-01-30 23:14:42.462299 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-01-30 23:14:42.484004 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:14:45.916641 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:14:45.918588 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000001/logs/progress.log
2025-01-30 23:14:48.410565 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2025-01-30 23:14:48.412474 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000002/logs/progress.log
2025-01-30 23:14:50.908262 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2025-01-30 23:14:50.909933 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000003/logs/progress.log
2025-01-30 23:14:53.369429 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2025-01-30 23:14:53.373158 DEBUG::tools.R/processChunks: done
2025-01-30 23:14:53.376293 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-01-30 23:14:53.394512 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.counts_exon.tab
2025-01-30 23:14:53.407817 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.counts_exon_disjoint.tab
2025-01-30 23:14:53.415884 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.counts_gene.tab
2025-01-30 23:14:53.421992 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.counts_gene_coding.tab
2025-01-30 23:14:53.427588 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.counts_gene_exonic.tab
2025-01-30 23:14:53.433098 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.counts_intergenic.tab
2025-01-30 23:14:53.442579 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.counts_intron.tab
2025-01-30 23:14:53.445198 INFO::countGenomicFeatures.R/mergeCounts: done
2025-01-30 23:14:53.450929 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.summary_counts.tab
2025-01-30 23:14:53.452533 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-01-30 23:14:53.766133 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-01-30 23:14:53.767316 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-01-30 23:14:53.902998 INFO::coverage.R/calculateCoverage: starting...
2025-01-30 23:14:53.907712 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:14:58.581051 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:14:58.584711 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000001/logs/progress.log
2025-01-30 23:15:01.012203 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2025-01-30 23:15:01.019356 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000002/logs/progress.log
2025-01-30 23:15:03.459292 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2025-01-30 23:15:03.466171 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/chunks/chunk_000003/logs/progress.log
2025-01-30 23:15:05.873425 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.04 minutes
2025-01-30 23:15:05.887194 DEBUG::tools.R/processChunks: done
2025-01-30 23:15:09.435093 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.coverage.RData
2025-01-30 23:15:09.43825 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.coverage.bw
2025-01-30 23:15:09.468479 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.summary_coverage.tab
2025-01-30 23:15:09.47198 INFO::coverage.R/calculateCoverage: done
2025-01-30 23:15:09.475875 INFO::analyzeVariants/analyzeVariants: starting ...
2025-01-30 23:15:09.773226 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-30 23:15:19.194503 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-30 23:15:19.335884 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-30 23:15:19.367194 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-30 23:15:19.369662 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.raw_variants.RData
2025-01-30 23:15:19.372485 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.filtered_variants.RData
2025-01-30 23:15:19.374785 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-30 23:15:19.376389 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-30 23:15:19.795887 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-30 23:15:19.977347 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/results/test_pe.summary_variants.tab
2025-01-30 23:15:19.981404 INFO::analyzeVariants/analyzeVariants: done
2025-01-30 23:15:19.990143 INFO::Pipeline run successful.
2025-01-30 23:15:20.57195 INFO::mergeLanes.R/doMergeLanes: starting...
2025-01-30 23:15:20.582606 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:15:20.587392 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.adapter_contaminated_1.RData
2025-01-30 23:15:20.593185 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-30 23:15:20.597837 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.adapter_contaminated_2.RData
2025-01-30 23:15:20.622923 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-30 23:15:20.62819 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.summary_preprocess.tab
2025-01-30 23:15:20.633331 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-30 23:15:21.072542 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-30 23:15:21.082149 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.summary_alignment.tab
2025-01-30 23:15:21.092394 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.summary_analyzed_bamstats.tab
2025-01-30 23:15:21.095491 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-30 23:15:21.359609 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.summary_target_lengths.tab
2025-01-30 23:15:21.416281 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-30 23:15:21.48166 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-01-30 23:15:21.505686 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.counts_exon.tab
2025-01-30 23:15:21.518589 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.counts_exon_disjoint.tab
2025-01-30 23:15:21.526156 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.counts_gene.tab
2025-01-30 23:15:21.532558 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.counts_gene_coding.tab
2025-01-30 23:15:21.538636 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.counts_gene_exonic.tab
2025-01-30 23:15:21.545049 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.counts_intergenic.tab
2025-01-30 23:15:21.557692 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.counts_intron.tab
2025-01-30 23:15:21.560505 INFO::countGenomicFeatures.R/mergeCounts: done
2025-01-30 23:15:21.567319 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.summary_counts.tab
2025-01-30 23:15:21.569268 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-01-30 23:15:21.819139 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-01-30 23:15:25.026731 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.coverage.RData
2025-01-30 23:15:25.032329 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.coverage.bw
2025-01-30 23:15:25.063581 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.summary_coverage.tab
2025-01-30 23:15:25.219501 INFO::analyzeVariants/analyzeVariants: starting ...
2025-01-30 23:15:25.53561 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-30 23:15:32.959973 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-30 23:15:33.154245 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-30 23:15:33.195257 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-30 23:15:33.198488 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.raw_variants.RData
2025-01-30 23:15:33.202023 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.filtered_variants.RData
2025-01-30 23:15:33.204805 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-30 23:15:33.206727 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-30 23:15:33.754251 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-30 23:15:34.015632 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.mergeLanes.28e338568beb99/merged/results/merged.summary_variants.tab
2025-01-30 23:15:34.020139 INFO::analyzeVariants/analyzeVariants: done
2025-01-30 23:15:34.026197 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= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:15:34.64731 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-30 23:15:34.665406 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:15:34.673111 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-30 23:15:34.67862 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:15:40.920424 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:15:40.922683 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/chunks/chunk_000001/logs/progress.log
2025-01-30 23:15:44.008779 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2025-01-30 23:15:44.110643 DEBUG::tools.R/processChunks: done
2025-01-30 23:15:44.114664 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:15:44.11736 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/results/test_pe.adapter_contaminated_1.RData
2025-01-30 23:15:44.120178 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-30 23:15:44.122632 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/results/test_pe.adapter_contaminated_2.RData
2025-01-30 23:15:44.139649 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-30 23:15:44.144476 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/results/test_pe.summary_preprocess.tab
2025-01-30 23:15:44.150039 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/bams/processed.aligner_input_1.fastq ...
2025-01-30 23:15:44.159344 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/bams/processed.aligner_input_2.fastq ...
2025-01-30 23:15:44.168408 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/reports/shortReadReport_1 ...
2025-01-30 23:15:45.799689 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.28e3385e5ba4d0/reports/shortReadReport_2 ...
2025-01-30 23:15:47.086231 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:15:47.485647 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-30 23:15:47.49193 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:15:47.495646 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-30 23:15:47.498021 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:15:51.23016 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:15:51.231641 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/chunks/chunk_000001/logs/progress.log
2025-01-30 23:15:54.211953 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2025-01-30 23:15:54.213542 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/chunks/chunk_000002/logs/progress.log
2025-01-30 23:15:56.821607 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-01-30 23:15:56.823061 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/chunks/chunk_000003/logs/progress.log
2025-01-30 23:15:59.464617 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2025-01-30 23:15:59.51264 DEBUG::tools.R/processChunks: done
2025-01-30 23:15:59.516853 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:15:59.518685 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/results/test_pe.adapter_contaminated_1.RData
2025-01-30 23:15:59.520762 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-30 23:15:59.522223 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/results/test_pe.adapter_contaminated_2.RData
2025-01-30 23:15:59.530504 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-30 23:15:59.532369 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/results/test_pe.summary_preprocess.tab
2025-01-30 23:15:59.534859 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/bams/processed.aligner_input_1.fastq ...
2025-01-30 23:15:59.539193 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/bams/processed.aligner_input_2.fastq ...
2025-01-30 23:15:59.542274 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/reports/shortReadReport_1 ...
2025-01-30 23:16:00.839845 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads.minichunks.28e3385647b8a9/reports/shortReadReport_2 ...
2025-01-30 23:16:01.927286 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:16:02.2069 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-30 23:16:02.215815 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-30 23:16:02.218464 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:16:05.528828 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:16:05.530331 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads_single_end.28e3384a2f13d8/chunks/chunk_000001/logs/progress.log
2025-01-30 23:16:07.942285 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2025-01-30 23:16:07.987453 DEBUG::tools.R/processChunks: done
2025-01-30 23:16:07.990263 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:16:07.992011 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads_single_end.28e3384a2f13d8/results/test_se.adapter_contaminated_1.RData
2025-01-30 23:16:07.998586 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-30 23:16:08.0003 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads_single_end.28e3384a2f13d8/results/test_se.summary_preprocess.tab
2025-01-30 23:16:08.002175 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads_single_end.28e3384a2f13d8/bams/processed.aligner_input_1.fastq ...
2025-01-30 23:16:08.005769 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpfwbFuI/test.preprocessReads_single_end.28e3384a2f13d8/reports/shortReadReport_1 ...
2025-01-30 23:16:09.426029 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.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2025-01-30 23:16:10.114711 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-30 23:16:10.122504 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2025-01-30 23:16:10.127582 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2025-01-30 23:16:10.13042 DEBUG::tools.R/processChunks: starting...
2025-01-30 23:16:13.38676 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-30 23:16:13.388177 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-01-30 23:16:16.197275 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2025-01-30 23:16:16.236107 DEBUG::tools.R/processChunks: done
2025-01-30 23:16:16.238168 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-30 23:16:16.23941 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-01-30 23:16:16.24085 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-30 23:16:16.242001 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-01-30 23:16:16.2473 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2500 highqual_reads=2500 adapter_contam=0 read_length=100 rRNA_contam_reads=0 processed_reads=2500 input_min_read_length=100 input_max_read_length=100 processed_min_read_length=71 processed_max_read_length=100
2025-01-30 23:16:16.248773 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-01-30 23:16:16.250515 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-01-30 23:16:16.254501 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-01-30 23:16:16.258645 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-01-30 23:17:10.131197 DEBUG::tools.R/traceMem: wired.mem=-74.870235 GiB
2025-01-30 23:18:10.19704 DEBUG::tools.R/traceMem: wired.mem=-74.863780 GiB
2025-01-30 23:19:10.261935 DEBUG::tools.R/traceMem: wired.mem=-75.242947 GiB
2025-01-30 23:20:10.328045 DEBUG::tools.R/traceMem: wired.mem=-71.726424 GiB
2025-01-30 23:21:10.393512 DEBUG::tools.R/traceMem: wired.mem=-68.247994 GiB
2025-01-30 23:22:10.460196 DEBUG::tools.R/traceMem: wired.mem=-61.673472 GiB
2025-01-30 23:23:10.525797 DEBUG::tools.R/traceMem: wired.mem=-59.894063 GiB
2025-01-30 23:24:10.591082 DEBUG::tools.R/traceMem: wired.mem=-62.449656 GiB
2025-01-30 23:25:10.660028 DEBUG::tools.R/traceMem: wired.mem=-70.298378 GiB
2025-01-30 23:26:10.727286 DEBUG::tools.R/traceMem: wired.mem=-76.164194 GiB
2025-01-30 23:27:10.793115 DEBUG::tools.R/traceMem: wired.mem=-71.992271 GiB
2025-01-30 23:28:10.858177 DEBUG::tools.R/traceMem: wired.mem=-75.813118 GiB
2025-01-30 23:29:10.882353 DEBUG::tools.R/traceMem: wired.mem=-74.337493 GiB
2025-01-30 23:30:10.948384 DEBUG::tools.R/traceMem: wired.mem=-66.017403 GiB
2025-01-30 23:31:11.014323 DEBUG::tools.R/traceMem: wired.mem=-63.903408 GiB
2025-01-30 23:32:11.080713 DEBUG::tools.R/traceMem: wired.mem=-70.749553 GiB
2025-01-30 23:33:11.146258 DEBUG::tools.R/traceMem: wired.mem=-71.366484 GiB
2025-01-30 23:34:11.21307 DEBUG::tools.R/traceMem: wired.mem=-71.384072 GiB
2025-01-30 23:35:11.278351 DEBUG::tools.R/traceMem: wired.mem=-75.847041 GiB
2025-01-30 23:36:11.344513 DEBUG::tools.R/traceMem: wired.mem=-71.361651 GiB
2025-01-30 23:37:11.409933 DEBUG::tools.R/traceMem: wired.mem=-70.839280 GiB
2025-01-30 23:38:11.475773 DEBUG::tools.R/traceMem: wired.mem=-74.449076 GiB
2025-01-30 23:39:11.541359 DEBUG::tools.R/traceMem: wired.mem=-82.610782 GiB
2025-01-30 23:40:11.60843 DEBUG::tools.R/traceMem: wired.mem=-73.000223 GiB
2025-01-30 23:41:11.673754 DEBUG::tools.R/traceMem: wired.mem=-63.454003 GiB
2025-01-30 23:42:11.739162 DEBUG::tools.R/traceMem: wired.mem=-69.941477 GiB
2025-01-30 23:43:11.805039 DEBUG::tools.R/traceMem: wired.mem=-65.845338 GiB
2025-01-30 23:44:11.870128 DEBUG::tools.R/traceMem: wired.mem=-77.660054 GiB
2025-01-30 23:45:11.934924 DEBUG::tools.R/traceMem: wired.mem=-73.118917 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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