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"	4744
palomino8	Windows Server 2022 Datacenter	x64	4.4.2 (2024-10-31 ucrt) -- "Pile of Leaves"	4487
merida1	macOS 12.7.5 Monterey	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4515
kjohnson1	macOS 13.6.6 Ventura	arm64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4467
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: 2024-12-20 01:09:23 -0500 (Fri, 20 Dec 2024)

EndedAt: 2024-12-20 01:49:24 -0500 (Fri, 20 Dec 2024)

EllapsedTime: 2400.8 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 ...Warning: unable to access index for repository https://CRAN.R-project.org/src/contrib:
  cannot open URL 'https://CRAN.R-project.org/src/contrib/PACKAGES'
 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:18:01.353548 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-20 01:18:01.361744 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
2024-12-20 01:18:01.365032 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
2024-12-20 01:18:01.367021 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:18:03.733434 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:18:03.734704 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/chunks/chunk_000001/logs/progress.log
2024-12-20 01:18:06.383364 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-12-20 01:18:06.384583 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/chunks/chunk_000002/logs/progress.log
2024-12-20 01:18:09.031736 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-12-20 01:18:09.032938 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/chunks/chunk_000003/logs/progress.log
2024-12-20 01:18:11.687145 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-12-20 01:18:11.709982 DEBUG::tools.R/processChunks: done
2024-12-20 01:18:11.713439 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:18:11.715595 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/results/test_pe.adapter_contaminated_1.RData
2024-12-20 01:18:11.718232 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-20 01:18:11.719795 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/results/test_pe.adapter_contaminated_2.RData
2024-12-20 01:18:11.728334 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
2024-12-20 01:18:11.730407 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/results/test_pe.summary_preprocess.tab
2024-12-20 01:18:11.733402 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/bams/processed.aligner_input_1.fastq ...
2024-12-20 01:18:11.738149 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/bams/processed.aligner_input_2.fastq ...
2024-12-20 01:18:11.741976 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/reports/shortReadReport_1 ...
2024-12-20 01:18:12.980191 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/reports/shortReadReport_2 ...
2024-12-20 01:18:13.942401 INFO::preprocessReads.R/preprocessReads: done
2024-12-20 01:18:14.028269 INFO::alignReads.R/alignReads: starting alignment...
2024-12-20 01:18:14.034345 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:18:16.470028 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:18:16.471539 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/chunks/chunk_000001/logs/progress.log
2024-12-20 01:18:19.241834 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-12-20 01:18:19.243845 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/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.
2024-12-20 01:18:21.823626 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-12-20 01:18:21.825374 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/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.
2024-12-20 01:18:24.432106 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-12-20 01:18:24.434293 DEBUG::tools.R/processChunks: done
2024-12-20 01:18:24.435561 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.
2024-12-20 01:18:24.634134 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-12-20 01:18:24.642293 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/results/test_pe.summary_alignment.tab
2024-12-20 01:18:24.649078 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/results/test_pe.summary_analyzed_bamstats.tab
2024-12-20 01:18:24.650622 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-12-20 01:18:24.885467 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.262eb2252b02b9/results/test_pe.summary_target_lengths.tab
2024-12-20 01:18:24.930273 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-12-20 01:18:24.931194 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:18:25.248842 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-20 01:18:25.251667 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
2024-12-20 01:18:25.337188 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-12-20 01:18:25.342297 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
2024-12-20 01:18:25.345324 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
2024-12-20 01:18:25.347245 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:18:27.891179 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:18:27.892448 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/chunks/chunk_000001/logs/progress.log
2024-12-20 01:18:30.528836 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-12-20 01:18:30.530006 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/chunks/chunk_000002/logs/progress.log
2024-12-20 01:18:33.13726 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-12-20 01:18:33.138457 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/chunks/chunk_000003/logs/progress.log
2024-12-20 01:18:35.809325 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-12-20 01:18:35.810488 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/chunks/chunk_000004/logs/progress.log
2024-12-20 01:18:38.412547 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.043 minutes
2024-12-20 01:18:38.434113 DEBUG::tools.R/processChunks: done
2024-12-20 01:18:38.43704 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:18:38.439111 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/results/test_pe.adapter_contaminated_1.RData
2024-12-20 01:18:38.441786 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-20 01:18:38.443313 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/results/test_pe.adapter_contaminated_2.RData
2024-12-20 01:18:38.452163 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
2024-12-20 01:18:38.454064 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/results/test_pe.summary_preprocess.tab
2024-12-20 01:18:38.457113 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/bams/processed.aligner_input_1.fastq ...
2024-12-20 01:18:38.461787 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/bams/processed.aligner_input_2.fastq ...
2024-12-20 01:18:38.465466 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/reports/shortReadReport_1 ...
2024-12-20 01:18:39.657859 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReads.sparsechunks.262eb245134785/reports/shortReadReport_2 ...
2024-12-20 01:18:40.609025 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:18:40.776304 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-12-20 01:18:40.780442 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/RtmpW1yVZ0/test.alignReadsOneSingleEnd.262eb29f46655/bams/test.alignReads /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-12-20 01:18:40.972214 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-12-20 01:18:41.05773 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReadsOneSingleEnd.262eb29f46655/results/test.alignReads.summary_alignment.tab
2024-12-20 01:18:41.096982 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.alignReadsOneSingleEnd.262eb29f46655/results/test.alignReads.summary_analyzed_bamstats.tab
2024-12-20 01:18:41.098414 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:18:41.365419 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.genotype.262eb26ddf8cc9/results/test_pe.coverage.RData
2024-12-20 01:18:41.367089 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.genotype.262eb26ddf8cc9/results/test_pe.coverage.bw
2024-12-20 01:18:41.47205 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.genotype.262eb26ddf8cc9/results/test_pe.summary_coverage.tab
2024-12-20 01:18:41.473647 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-20 01:18:51.123161 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-20 01:18:51.198298 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-20 01:18:51.213236 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-20 01:18:51.214547 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.genotype.262eb26ddf8cc9/results/test_pe.raw_variants.RData
2024-12-20 01:18:51.216789 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.genotype.262eb26ddf8cc9/results/test_pe.filtered_variants.RData
2024-12-20 01:18:51.218043 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-20 01:18:51.21911 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-20 01:18:51.592475 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-20 01:18:51.593656 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-12-20 01:19:44.615768 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-20 01:19:44.985779 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-20 01:19:44.986586 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:19:45.357315 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-20 01:19:54.806258 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-20 01:19:54.873362 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-20 01:19:54.887894 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-20 01:19:54.889146 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.262eb267580ec2/results/test_pe.raw_variants.RData
2024-12-20 01:19:54.891391 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.262eb267580ec2/results/test_pe.filtered_variants.RData
2024-12-20 01:19:54.892624 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:19:55.022222 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-20 01:20:04.494267 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-20 01:20:04.543474 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-20 01:20:04.557774 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-20 01:20:04.558919 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.filters.262eb25ba20121/results/test_pe.raw_variants.RData
2024-12-20 01:20:04.561105 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.filters.262eb25ba20121/results/test_pe.filtered_variants.RData
2024-12-20 01:20:04.562398 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-20 01:20:04.5637 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-20 01:20:13.820976 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-20 01:20:13.854798 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-20 01:20:13.869246 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-20 01:20:13.870411 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.filters.262eb25ba20121/results/test_pe.raw_variants.RData
2024-12-20 01:20:13.872725 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.filters.262eb25ba20121/results/test_pe.filtered_variants.RData
2024-12-20 01:20:13.874553 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:20:15.583167 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-20 01:20:15.584662 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-12-20 01:20:18.081053 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-20 01:20:18.146127 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-20 01:20:18.160451 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-20 01:20:18.161623 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.which.262eb210b6960d/results/test_pe.raw_variants.RData
2024-12-20 01:20:18.163085 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.wrap.callVariants.which.262eb210b6960d/results/test_pe.filtered_variants.RData
2024-12-20 01:20:18.164232 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:20:18.292622 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-20 01:20:18.293792 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:20:18.463028 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-20 01:20:18.659384 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  ... 2024-12-20 01:21:06.896008 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/yzokbexi/merged/results/bla.coverage.RData
2024-12-20 01:21:06.898763 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/yzokbexi/merged/results/bla.coverage.bw
2024-12-20 01:21:06.973242 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/yzokbexi/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-12-20 01:21:07.980674 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/nleyfoih/merged/results/bla.coverage.RData
2024-12-20 01:21:07.982313 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/nleyfoih/merged/results/bla.coverage.bw
2024-12-20 01:21:07.992767 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/nleyfoih/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:09.051525 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-12-20 01:21:09.052515 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.detectRRNA.262eb24af8963b/bams/rRNA_contam/input1.fastq
2024-12-20 01:21:09.055532 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/RtmpW1yVZ0/test.detectRRNA.262eb24af8963b/bams/rRNA_contam/test_se /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.detectRRNA.262eb24af8963b/bams/rRNA_contam/input1.fastq 2>&1
2024-12-20 01:21:09.189082 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-12-20 01:21:09.190041 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:09.331379 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-12-20 01:21:09.332266 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.detectRRNA.paired_end.262eb26d1349a7/bams/rRNA_contam/input1.fastq
2024-12-20 01:21:09.333655 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.detectRRNA.paired_end.262eb26d1349a7/bams/rRNA_contam/input2.fastq
2024-12-20 01:21:09.33566 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/RtmpW1yVZ0/test.detectRRNA.paired_end.262eb26d1349a7/bams/rRNA_contam/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.detectRRNA.paired_end.262eb26d1349a7/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.detectRRNA.paired_end.262eb26d1349a7/bams/rRNA_contam/input2.fastq 2>&1
2024-12-20 01:21:09.555472 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-12-20 01:21:09.556388 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-12-20 01:21:09.574107 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/RtmpW1yVZ0/test_get_rRNA_idsamjyctfl/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test_get_rRNA_idsamjyctfl/1.fastq -a paired /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test_get_rRNA_idsamjyctfl/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-12-20 01:21:09.810132 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/RtmpW1yVZ0/test_get_rRNAIds_randomnpbuxhso/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test_get_rRNAIds_randomnpbuxhso/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-12-20 01:21:10.012666 INFO::filterQuality.R/filterQuality: filterByLength...
2024-12-20 01:21:10.014006 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-12-20 01:21:10.014839 INFO::filterQuality.R/filterByLength: done
2024-12-20 01:21:10.058188 INFO::filterQuality.R/filterQuality: filterByLength...
2024-12-20 01:21:10.059072 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-12-20 01:21:10.059861 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-12-20 01:21:10.105993 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-20 01:21:10.114219 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-12-20 01:21:10.115158 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-20 01:21:10.119138 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-12-20 01:21:10.120007 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-20 01:21:10.123966 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-12-20 01:21:10.124836 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-20 01:21:10.128774 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:10.405556 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
2024-12-20 01:21:10.407658 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:10.54127 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
2024-12-20 01:21:10.607232 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-12-20 01:21:10.609766 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
2024-12-20 01:21:10.611804 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:10.792443 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:10.92456 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:11.047501 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
2024-12-20 01:21:11.089848 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-12-20 01:21:11.092044 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
2024-12-20 01:21:11.094023 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:11.2603 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
2024-12-20 01:21:11.300527 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-12-20 01:21:11.302714 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
2024-12-20 01:21:11.304714 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/RtmpW1yVZ0/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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:21:11.9405 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-20 01:21:11.946207 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
2024-12-20 01:21:11.949512 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
2024-12-20 01:21:11.95166 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:21:14.505728 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:21:14.507045 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000001/logs/progress.log
2024-12-20 01:21:17.046771 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-12-20 01:21:17.047982 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000002/logs/progress.log
2024-12-20 01:21:19.607921 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-12-20 01:21:19.609415 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000003/logs/progress.log
2024-12-20 01:21:22.183174 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-12-20 01:21:22.230093 DEBUG::tools.R/processChunks: done
2024-12-20 01:21:22.233252 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:21:22.234876 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.adapter_contaminated_1.RData
2024-12-20 01:21:22.236741 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-20 01:21:22.238142 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.adapter_contaminated_2.RData
2024-12-20 01:21:22.245842 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
2024-12-20 01:21:22.247628 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.summary_preprocess.tab
2024-12-20 01:21:22.25 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/bams/processed.aligner_input_1.fastq ...
2024-12-20 01:21:22.253809 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/bams/processed.aligner_input_2.fastq ...
2024-12-20 01:21:22.257244 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/reports/shortReadReport_1 ...
2024-12-20 01:21:24.542943 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/reports/shortReadReport_2 ...
2024-12-20 01:21:25.529795 INFO::preprocessReads.R/preprocessReads: done
2024-12-20 01:21:25.653733 INFO::alignReads.R/alignReads: starting alignment...
2024-12-20 01:21:25.658165 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:21:28.319403 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:21:28.321025 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000001/logs/progress.log
2024-12-20 01:21:30.850674 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-12-20 01:21:30.852186 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/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.
2024-12-20 01:21:33.402766 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-12-20 01:21:33.404336 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/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.
2024-12-20 01:21:35.959134 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-12-20 01:21:35.962392 DEBUG::tools.R/processChunks: done
2024-12-20 01:21:35.964329 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.
2024-12-20 01:21:36.162949 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-12-20 01:21:36.170396 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.summary_alignment.tab
2024-12-20 01:21:36.176839 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.summary_analyzed_bamstats.tab
2024-12-20 01:21:36.178562 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-12-20 01:21:36.397292 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.summary_target_lengths.tab
2024-12-20 01:21:36.44253 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-12-20 01:21:36.44354 INFO::alignReads.R/alignReads: done
2024-12-20 01:21:36.536679 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-12-20 01:21:36.555217 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:21:39.225244 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:21:39.226737 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000001/logs/progress.log
2024-12-20 01:21:41.618506 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-12-20 01:21:41.619846 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000002/logs/progress.log
2024-12-20 01:21:44.020922 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2024-12-20 01:21:44.022597 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000003/logs/progress.log
2024-12-20 01:21:46.430437 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.04 minutes
2024-12-20 01:21:46.432696 DEBUG::tools.R/processChunks: done
2024-12-20 01:21:46.434232 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-12-20 01:21:46.447372 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.counts_exon.tab
2024-12-20 01:21:46.457973 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.counts_exon_disjoint.tab
2024-12-20 01:21:46.464427 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.counts_gene.tab
2024-12-20 01:21:46.469401 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.counts_gene_coding.tab
2024-12-20 01:21:46.474203 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.counts_gene_exonic.tab
2024-12-20 01:21:46.479095 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.counts_intergenic.tab
2024-12-20 01:21:46.488046 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.counts_intron.tab
2024-12-20 01:21:46.490437 INFO::countGenomicFeatures.R/mergeCounts: done
2024-12-20 01:21:46.495235 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.summary_counts.tab
2024-12-20 01:21:46.496641 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-12-20 01:21:46.787875 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-12-20 01:21:46.788691 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-12-20 01:21:46.887587 INFO::coverage.R/calculateCoverage: starting...
2024-12-20 01:21:46.891676 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:21:49.476188 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:21:49.477713 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000001/logs/progress.log
2024-12-20 01:21:51.642621 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-12-20 01:21:51.644172 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000002/logs/progress.log
2024-12-20 01:21:53.82112 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-12-20 01:21:53.822839 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/chunks/chunk_000003/logs/progress.log
2024-12-20 01:21:56.026912 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2024-12-20 01:21:56.028992 DEBUG::tools.R/processChunks: done
2024-12-20 01:21:57.18398 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.coverage.RData
2024-12-20 01:21:57.185316 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.coverage.bw
2024-12-20 01:21:57.195875 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.summary_coverage.tab
2024-12-20 01:21:57.197008 INFO::coverage.R/calculateCoverage: done
2024-12-20 01:21:57.198631 INFO::analyzeVariants/analyzeVariants: starting ...
2024-12-20 01:21:57.277819 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-20 01:22:00.041137 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-20 01:22:00.111721 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-20 01:22:00.127239 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-20 01:22:00.128555 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.raw_variants.RData
2024-12-20 01:22:00.1301 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.filtered_variants.RData
2024-12-20 01:22:00.13133 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-20 01:22:00.132263 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-20 01:22:00.347363 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-20 01:22:00.44607 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/results/test_pe.summary_variants.tab
2024-12-20 01:22:00.452448 INFO::analyzeVariants/analyzeVariants: done
2024-12-20 01:22:00.457656 INFO::Pipeline run successful.
2024-12-20 01:22:00.625967 INFO::mergeLanes.R/doMergeLanes: starting...
2024-12-20 01:22:00.631011 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:22:00.633178 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.adapter_contaminated_1.RData
2024-12-20 01:22:00.635956 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-20 01:22:00.637866 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.adapter_contaminated_2.RData
2024-12-20 01:22:00.649205 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
2024-12-20 01:22:00.651427 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.summary_preprocess.tab
2024-12-20 01:22:00.653549 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.
2024-12-20 01:22:00.883238 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-12-20 01:22:00.890723 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.summary_alignment.tab
2024-12-20 01:22:00.898901 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.summary_analyzed_bamstats.tab
2024-12-20 01:22:00.900967 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-12-20 01:22:01.136652 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.summary_target_lengths.tab
2024-12-20 01:22:01.186587 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-12-20 01:22:01.240539 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-12-20 01:22:01.260653 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.counts_exon.tab
2024-12-20 01:22:01.272038 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.counts_exon_disjoint.tab
2024-12-20 01:22:01.278549 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.counts_gene.tab
2024-12-20 01:22:01.283762 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.counts_gene_coding.tab
2024-12-20 01:22:01.288948 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.counts_gene_exonic.tab
2024-12-20 01:22:01.294457 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.counts_intergenic.tab
2024-12-20 01:22:01.305838 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.counts_intron.tab
2024-12-20 01:22:01.308465 INFO::countGenomicFeatures.R/mergeCounts: done
2024-12-20 01:22:01.31449 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.summary_counts.tab
2024-12-20 01:22:01.316164 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-12-20 01:22:01.549549 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-12-20 01:22:03.314666 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.coverage.RData
2024-12-20 01:22:03.316892 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.coverage.bw
2024-12-20 01:22:03.330778 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.summary_coverage.tab
2024-12-20 01:22:03.37306 INFO::analyzeVariants/analyzeVariants: starting ...
2024-12-20 01:22:03.471571 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-20 01:22:06.214565 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-20 01:22:06.279526 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-20 01:22:06.293838 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-20 01:22:06.295061 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.raw_variants.RData
2024-12-20 01:22:06.296521 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.filtered_variants.RData
2024-12-20 01:22:06.297668 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-20 01:22:06.298595 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-20 01:22:06.491005 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-20 01:22:06.580126 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.mergeLanes.262eb2733a6846/merged/results/merged.summary_variants.tab
2024-12-20 01:22:06.581996 INFO::analyzeVariants/analyzeVariants: done
2024-12-20 01:22:06.584733 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



Executing test function test.markDuplicates_w_outfile  ... Timing stopped at: 0.001 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:22:06.849634 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-20 01:22:06.855525 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
2024-12-20 01:22:06.858824 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
2024-12-20 01:22:06.860873 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:22:09.608075 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:22:09.609438 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/chunks/chunk_000001/logs/progress.log
2024-12-20 01:22:12.190352 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-12-20 01:22:12.234948 DEBUG::tools.R/processChunks: done
2024-12-20 01:22:12.237087 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:22:12.238486 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/results/test_pe.adapter_contaminated_1.RData
2024-12-20 01:22:12.240011 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-20 01:22:12.241243 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/results/test_pe.adapter_contaminated_2.RData
2024-12-20 01:22:12.24698 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
2024-12-20 01:22:12.248562 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/results/test_pe.summary_preprocess.tab
2024-12-20 01:22:12.250376 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/bams/processed.aligner_input_1.fastq ...
2024-12-20 01:22:12.253438 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/bams/processed.aligner_input_2.fastq ...
2024-12-20 01:22:12.256531 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/reports/shortReadReport_1 ...
2024-12-20 01:22:14.55159 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.262eb213424277/reports/shortReadReport_2 ...
2024-12-20 01:22:15.542754 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:22:15.804723 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-20 01:22:15.810525 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
2024-12-20 01:22:15.813719 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
2024-12-20 01:22:15.815837 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:22:18.504472 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:22:18.505735 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/chunks/chunk_000001/logs/progress.log
2024-12-20 01:22:21.041004 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-12-20 01:22:21.042221 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/chunks/chunk_000002/logs/progress.log
2024-12-20 01:22:23.560745 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-12-20 01:22:23.561936 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/chunks/chunk_000003/logs/progress.log
2024-12-20 01:22:26.129364 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-12-20 01:22:27.484017 DEBUG::tools.R/processChunks: done
2024-12-20 01:22:27.486031 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:22:27.487336 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/results/test_pe.adapter_contaminated_1.RData
2024-12-20 01:22:27.488997 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-20 01:22:27.490222 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/results/test_pe.adapter_contaminated_2.RData
2024-12-20 01:22:27.496403 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
2024-12-20 01:22:27.49774 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/results/test_pe.summary_preprocess.tab
2024-12-20 01:22:27.499571 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/bams/processed.aligner_input_1.fastq ...
2024-12-20 01:22:27.502944 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/bams/processed.aligner_input_2.fastq ...
2024-12-20 01:22:27.505623 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/reports/shortReadReport_1 ...
2024-12-20 01:22:28.632273 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads.minichunks.262eb227426bb3/reports/shortReadReport_2 ...
2024-12-20 01:22:29.687471 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/RtmpW1yVZ0/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-20 01:22:29.917428 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-20 01:22:29.923069 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
2024-12-20 01:22:29.925182 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:22:32.417226 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:22:32.418494 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads_single_end.262eb217db390/chunks/chunk_000001/logs/progress.log
2024-12-20 01:22:34.748366 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-12-20 01:22:35.897861 DEBUG::tools.R/processChunks: done
2024-12-20 01:22:35.899417 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:22:35.900576 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads_single_end.262eb217db390/results/test_se.adapter_contaminated_1.RData
2024-12-20 01:22:35.905274 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
2024-12-20 01:22:35.906611 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads_single_end.262eb217db390/results/test_se.summary_preprocess.tab
2024-12-20 01:22:35.908026 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads_single_end.262eb217db390/bams/processed.aligner_input_1.fastq ...
2024-12-20 01:22:35.910977 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpW1yVZ0/test.preprocessReads_single_end.262eb217db390/reports/shortReadReport_1 ...
2024-12-20 01:22:37.037988 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 
2024-12-20 01:22:37.592496 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-20 01:22:37.597864 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
2024-12-20 01:22:37.601074 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
2024-12-20 01:22:37.602923 DEBUG::tools.R/processChunks: starting...
2024-12-20 01:22:41.107549 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-20 01:22:41.108848 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-12-20 01:22:43.831578 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-12-20 01:22:43.867431 DEBUG::tools.R/processChunks: done
2024-12-20 01:22:43.869313 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-20 01:22:43.870534 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-12-20 01:22:43.871878 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-20 01:22:43.873012 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-12-20 01:22:43.878103 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
2024-12-20 01:22:43.879565 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-12-20 01:22:43.881191 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-12-20 01:22:43.885792 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-12-20 01:22:43.889086 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-12-20 01:23:37.622047 DEBUG::tools.R/traceMem: wired.mem=-93.279982 GiB
2024-12-20 01:24:37.667987 DEBUG::tools.R/traceMem: wired.mem=-92.428898 GiB
2024-12-20 01:25:37.734458 DEBUG::tools.R/traceMem: wired.mem=-93.318935 GiB
2024-12-20 01:26:37.80123 DEBUG::tools.R/traceMem: wired.mem=-95.437705 GiB
2024-12-20 01:27:37.869443 DEBUG::tools.R/traceMem: wired.mem=-91.198263 GiB
2024-12-20 01:28:37.935656 DEBUG::tools.R/traceMem: wired.mem=-1.816261 GiB
2024-12-20 01:29:38.001267 DEBUG::tools.R/traceMem: wired.mem=-99.644330 GiB
2024-12-20 01:30:38.066557 DEBUG::tools.R/traceMem: wired.mem=-100.415967 GiB
2024-12-20 01:31:38.132969 DEBUG::tools.R/traceMem: wired.mem=-99.177828 GiB
2024-12-20 01:32:38.200111 DEBUG::tools.R/traceMem: wired.mem=-92.491928 GiB
2024-12-20 01:33:38.26686 DEBUG::tools.R/traceMem: wired.mem=-89.078051 GiB
2024-12-20 01:34:38.33422 DEBUG::tools.R/traceMem: wired.mem=-88.791110 GiB
2024-12-20 01:35:38.400054 DEBUG::tools.R/traceMem: wired.mem=-87.887155 GiB
2024-12-20 01:36:38.465585 DEBUG::tools.R/traceMem: wired.mem=-96.091009 GiB
2024-12-20 01:37:38.510801 DEBUG::tools.R/traceMem: wired.mem=-96.816771 GiB
2024-12-20 01:38:38.576662 DEBUG::tools.R/traceMem: wired.mem=-90.304967 GiB
2024-12-20 01:39:38.642437 DEBUG::tools.R/traceMem: wired.mem=-91.954901 GiB
2024-12-20 01:40:38.70825 DEBUG::tools.R/traceMem: wired.mem=-84.324815 GiB
2024-12-20 01:41:38.746666 DEBUG::tools.R/traceMem: wired.mem=-88.455565 GiB
2024-12-20 01:42:38.813987 DEBUG::tools.R/traceMem: wired.mem=-82.495459 GiB
2024-12-20 01:43:38.879475 DEBUG::tools.R/traceMem: wired.mem=-87.882576 GiB
2024-12-20 01:44:38.945772 DEBUG::tools.R/traceMem: wired.mem=-93.879013 GiB
2024-12-20 01:45:39.012151 DEBUG::tools.R/traceMem: wired.mem=-95.628841 GiB
2024-12-20 01:46:39.077609 DEBUG::tools.R/traceMem: wired.mem=-98.744029 GiB
2024-12-20 01:47:39.144503 DEBUG::tools.R/traceMem: wired.mem=-91.890397 GiB
2024-12-20 01:48:39.212204 DEBUG::tools.R/traceMem: wired.mem=-89.471316 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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