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

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
taishan	Linux (openEuler 24.03 LTS)	aarch64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4358
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 taishan

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.
- See Martin Grigorov's blog post for how to debug Linux ARM64 related issues on a x86_64 host.

raw results

Summary

Package: HTSeqGenie

Version: 4.36.0

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

StartedAt: 2025-01-09 00:12:58 -0000 (Thu, 09 Jan 2025)

EndedAt: 2025-01-09 00:25:59 -0000 (Thu, 09 Jan 2025)

EllapsedTime: 780.8 seconds

RetCode: 0

Status: OK

CheckDir: HTSeqGenie.Rcheck

Warnings: 0

Command output

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

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

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

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

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

Functions with \usage entries need to have the appropriate \alias
entries, and all their arguments documented.
The \usage entries must correspond to syntactically valid R code.
See chapter ‘Writing R documentation files’ in the ‘Writing R
Extensions’ manual.
* checking Rd contents ... OK
* checking for unstated dependencies in examples ... OK
* checking files in ‘vignettes’ ... OK
* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
  Running ‘doRUnit.R’
 OK
* checking for unstated dependencies in vignettes ... OK
* checking package vignettes ... OK
* checking running R code from vignettes ... SKIPPED
* checking re-building of vignette outputs ... SKIPPED
* checking PDF version of manual ... OK
* DONE

Status: 7 NOTEs
See
  ‘/home/biocbuild/bbs-3.20-bioc/meat/HTSeqGenie.Rcheck/00check.log’
for details.

Installation output

HTSeqGenie.Rcheck/00install.out

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/R/R/bin/R CMD INSTALL HTSeqGenie
###
##############################################################################
##############################################################################


* installing to library ‘/home/biocbuild/R/R-4.4.2/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: aarch64-unknown-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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:19:18.114159 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-09 00:19:18.122664 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:19:18.12779 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-09 00:19:18.130369 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:19:20.464704 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:19:20.466562 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/chunks/chunk_000001/logs/progress.log
2025-01-09 00:19:23.246682 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-01-09 00:19:23.2485 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/chunks/chunk_000002/logs/progress.log
2025-01-09 00:19:26.062229 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2025-01-09 00:19:26.064053 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/chunks/chunk_000003/logs/progress.log
2025-01-09 00:19:28.831158 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-01-09 00:19:28.865648 DEBUG::tools.R/processChunks: done
2025-01-09 00:19:28.870305 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:19:28.873287 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/results/test_pe.adapter_contaminated_1.RData
2025-01-09 00:19:28.876942 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-09 00:19:28.879257 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/results/test_pe.adapter_contaminated_2.RData
2025-01-09 00:19:28.890807 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-09 00:19:28.894024 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/results/test_pe.summary_preprocess.tab
2025-01-09 00:19:28.898291 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/bams/processed.aligner_input_1.fastq ...
2025-01-09 00:19:28.904525 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/bams/processed.aligner_input_2.fastq ...
2025-01-09 00:19:28.909471 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/reports/shortReadReport_1 ...
2025-01-09 00:19:30.685113 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/reports/shortReadReport_2 ...
2025-01-09 00:19:32.152468 INFO::preprocessReads.R/preprocessReads: done
2025-01-09 00:19:32.211035 INFO::alignReads.R/alignReads: starting alignment...
2025-01-09 00:19:32.21655 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:19:34.655579 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:19:34.657511 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/chunks/chunk_000001/logs/progress.log
2025-01-09 00:19:37.281589 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-01-09 00:19:37.283713 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/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.
2025-01-09 00:19:39.922909 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-01-09 00:19:39.924977 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-09 00:19:42.59933 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-01-09 00:19:42.602492 DEBUG::tools.R/processChunks: done
2025-01-09 00:19:42.604275 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 "T" 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 "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-09 00:19:42.905176 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-09 00:19:42.91609 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/results/test_pe.summary_alignment.tab
2025-01-09 00:19:42.926056 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/results/test_pe.summary_analyzed_bamstats.tab
2025-01-09 00:19:42.928419 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-09 00:19:43.202543 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.3b1c297b2392b0/results/test_pe.summary_target_lengths.tab
2025-01-09 00:19:43.260751 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-09 00:19:43.261984 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:19:43.538045 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-09 00:19:43.54115 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:19:43.612943 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-01-09 00:19:43.619267 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:19:43.62352 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-09 00:19:43.625929 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:19:46.034467 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:19:46.036402 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/chunks/chunk_000001/logs/progress.log
2025-01-09 00:19:48.820416 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2025-01-09 00:19:48.822369 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/chunks/chunk_000002/logs/progress.log
2025-01-09 00:19:51.556338 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-01-09 00:19:51.55812 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/chunks/chunk_000003/logs/progress.log
2025-01-09 00:19:54.386694 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2025-01-09 00:19:54.388514 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/chunks/chunk_000004/logs/progress.log
2025-01-09 00:19:57.100496 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2025-01-09 00:19:57.136337 DEBUG::tools.R/processChunks: done
2025-01-09 00:19:57.140779 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:19:57.143932 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/results/test_pe.adapter_contaminated_1.RData
2025-01-09 00:19:57.148126 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-09 00:19:57.15061 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/results/test_pe.adapter_contaminated_2.RData
2025-01-09 00:19:57.16384 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-09 00:19:57.166745 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/results/test_pe.summary_preprocess.tab
2025-01-09 00:19:57.17127 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/bams/processed.aligner_input_1.fastq ...
2025-01-09 00:19:57.177832 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/bams/processed.aligner_input_2.fastq ...
2025-01-09 00:19:57.182955 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/reports/shortReadReport_1 ...
2025-01-09 00:19:58.850037 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReads.sparsechunks.3b1c293791878/reports/shortReadReport_2 ...
2025-01-09 00:20:00.209106 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:20:00.396967 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-01-09 00:20:00.402623 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/tmp/RtmpE5zeW8/test.alignReadsOneSingleEnd.3b1c293c21e4e9/bams/test.alignReads /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-01-09 00:20:00.517237 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-01-09 00:20:00.653065 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReadsOneSingleEnd.3b1c293c21e4e9/results/test.alignReads.summary_alignment.tab
2025-01-09 00:20:00.704774 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.alignReadsOneSingleEnd.3b1c293c21e4e9/results/test.alignReads.summary_analyzed_bamstats.tab
2025-01-09 00:20:00.706869 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0 0.003 0.003
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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:20:01.185577 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.genotype.3b1c29f0103fd/results/test_pe.coverage.RData
2025-01-09 00:20:01.18798 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.genotype.3b1c29f0103fd/results/test_pe.coverage.bw
2025-01-09 00:20:01.346213 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.genotype.3b1c29f0103fd/results/test_pe.summary_coverage.tab
2025-01-09 00:20:01.348731 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:20:13.004974 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:20:13.146531 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:20:13.174926 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:20:13.177176 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.genotype.3b1c29f0103fd/results/test_pe.raw_variants.RData
2025-01-09 00:20:13.180462 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.genotype.3b1c29f0103fd/results/test_pe.filtered_variants.RData
2025-01-09 00:20:13.182546 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-09 00:20:13.184394 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-09 00:20:13.838601 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-09 00:20:13.840347 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-01-09 00:21:33.075309 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-09 00:21:33.612309 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-09 00:21:33.613402 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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:21:34.158514 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:21:45.434807 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:21:45.550283 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:21:45.574031 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:21:45.575924 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.3b1c29bc07c51/results/test_pe.raw_variants.RData
2025-01-09 00:21:45.578948 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.3b1c29bc07c51/results/test_pe.filtered_variants.RData
2025-01-09 00:21:45.580777 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:21:45.772243 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:21:57.825238 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:21:57.907107 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:21:57.930842 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:21:57.932689 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.filters.3b1c2969e23cde/results/test_pe.raw_variants.RData
2025-01-09 00:21:57.935598 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.filters.3b1c2969e23cde/results/test_pe.filtered_variants.RData
2025-01-09 00:21:57.938036 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-09 00:21:57.940453 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:22:09.339877 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:22:09.398573 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:22:09.423808 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:22:09.425765 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.filters.3b1c2969e23cde/results/test_pe.raw_variants.RData
2025-01-09 00:22:09.42933 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.filters.3b1c2969e23cde/results/test_pe.filtered_variants.RData
2025-01-09 00:22:09.432074 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:22:09.755387 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:22:09.757298 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-01-09 00:22:13.195429 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:22:13.30759 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:22:13.329783 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:22:13.331594 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.which.3b1c2955315a37/results/test_pe.raw_variants.RData
2025-01-09 00:22:13.3338 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.wrap.callVariants.which.3b1c2955315a37/results/test_pe.filtered_variants.RData
2025-01-09 00:22:13.335478 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:22:13.520922 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-09 00:22:13.522545 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:22:15.170885 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-09 00:22:15.43097 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



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



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



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



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



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



Executing test function test.mergeCoverage  ... 2025-01-09 00:23:16.331932 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/kjzrgvqo/merged/results/bla.coverage.RData
2025-01-09 00:23:16.335105 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpE5zeW8/kjzrgvqo/merged/results/bla.coverage.bw
2025-01-09 00:23:16.415519 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/kjzrgvqo/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-01-09 00:23:17.400536 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/jrfaihbw/merged/results/bla.coverage.RData
2025-01-09 00:23:17.402565 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpE5zeW8/jrfaihbw/merged/results/bla.coverage.bw
2025-01-09 00:23:17.41612 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/jrfaihbw/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:18.908462 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-01-09 00:23:18.909947 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpE5zeW8/test.detectRRNA.3b1c295d5a9cac/bams/rRNA_contam/input1.fastq
2025-01-09 00:23:18.914124 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/tmp/RtmpE5zeW8/test.detectRRNA.3b1c295d5a9cac/bams/rRNA_contam/test_se /home/biocbuild/tmp/RtmpE5zeW8/test.detectRRNA.3b1c295d5a9cac/bams/rRNA_contam/input1.fastq 2>&1
2025-01-09 00:23:19.035316 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-01-09 00:23:19.036673 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:19.218299 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-01-09 00:23:19.219566 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpE5zeW8/test.detectRRNA.paired_end.3b1c296e0cba3c/bams/rRNA_contam/input1.fastq
2025-01-09 00:23:19.221534 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpE5zeW8/test.detectRRNA.paired_end.3b1c296e0cba3c/bams/rRNA_contam/input2.fastq
2025-01-09 00:23:19.224456 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/tmp/RtmpE5zeW8/test.detectRRNA.paired_end.3b1c296e0cba3c/bams/rRNA_contam/test_pe /home/biocbuild/tmp/RtmpE5zeW8/test.detectRRNA.paired_end.3b1c296e0cba3c/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/tmp/RtmpE5zeW8/test.detectRRNA.paired_end.3b1c296e0cba3c/bams/rRNA_contam/input2.fastq 2>&1
2025-01-09 00:23:19.470258 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-01-09 00:23:19.471517 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-01-09 00:23:19.496594 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/tmp/RtmpE5zeW8/test_get_rRNA_idsotawvrcx/test_pe /home/biocbuild/tmp/RtmpE5zeW8/test_get_rRNA_idsotawvrcx/1.fastq -a paired /home/biocbuild/tmp/RtmpE5zeW8/test_get_rRNA_idsotawvrcx/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-01-09 00:23:19.769617 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/tmp/RtmpE5zeW8/test_get_rRNAIds_randomncvkhzys/test_pe /home/biocbuild/tmp/RtmpE5zeW8/test_get_rRNAIds_randomncvkhzys/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-01-09 00:23:19.915754 INFO::filterQuality.R/filterQuality: filterByLength...
2025-01-09 00:23:19.917537 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-01-09 00:23:19.918696 INFO::filterQuality.R/filterByLength: done
2025-01-09 00:23:19.978034 INFO::filterQuality.R/filterQuality: filterByLength...
2025-01-09 00:23:19.97918 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-01-09 00:23:19.980319 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-01-09 00:23:20.047532 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-09 00:23:20.059231 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-09 00:23:20.060671 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-09 00:23:20.06673 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-09 00:23:20.068096 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-09 00:23:20.073813 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-01-09 00:23:20.075181 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-01-09 00:23:20.081455 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



Executing test function test.realignIndelsGATK  ... Timing stopped at: 0 0 0.001
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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:20.451164 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:20.454475 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:20.672373 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:20.799651 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-09 00:23:20.803585 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:20.807012 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:21.091829 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:21.276651 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:21.482036 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:21.588581 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-09 00:23:21.591919 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:21.594914 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:21.850838 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:21.908105 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-01-09 00:23:21.911411 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:21.914452 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/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/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:23:22.783641 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-09 00:23:22.79042 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:23:22.795281 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-09 00:23:22.798404 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:23:25.322858 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:23:25.324738 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000001/logs/progress.log
2025-01-09 00:23:27.995256 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-01-09 00:23:27.997179 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000002/logs/progress.log
2025-01-09 00:23:30.683628 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-01-09 00:23:30.685459 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000003/logs/progress.log
2025-01-09 00:23:33.370903 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-01-09 00:23:33.420254 DEBUG::tools.R/processChunks: done
2025-01-09 00:23:33.424212 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:23:33.426735 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.adapter_contaminated_1.RData
2025-01-09 00:23:33.430048 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-09 00:23:33.432803 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.adapter_contaminated_2.RData
2025-01-09 00:23:33.445892 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-09 00:23:33.448786 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.summary_preprocess.tab
2025-01-09 00:23:33.452621 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/bams/processed.aligner_input_1.fastq ...
2025-01-09 00:23:33.45952 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/bams/processed.aligner_input_2.fastq ...
2025-01-09 00:23:33.465422 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/reports/shortReadReport_1 ...
2025-01-09 00:23:35.177804 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/reports/shortReadReport_2 ...
2025-01-09 00:23:36.550879 INFO::preprocessReads.R/preprocessReads: done
2025-01-09 00:23:36.627745 INFO::alignReads.R/alignReads: starting alignment...
2025-01-09 00:23:36.632742 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:23:39.204583 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:23:39.206651 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000001/logs/progress.log
2025-01-09 00:23:41.790781 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-01-09 00:23:41.793096 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/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.
2025-01-09 00:23:44.396047 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-01-09 00:23:44.398358 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-09 00:23:46.983462 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-01-09 00:23:46.986689 DEBUG::tools.R/processChunks: done
2025-01-09 00:23:46.988575 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 "T" 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 "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-09 00:23:47.272373 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-09 00:23:47.28247 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.summary_alignment.tab
2025-01-09 00:23:47.292287 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.summary_analyzed_bamstats.tab
2025-01-09 00:23:47.29467 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-09 00:23:47.537265 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.summary_target_lengths.tab
2025-01-09 00:23:47.595098 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-09 00:23:47.596389 INFO::alignReads.R/alignReads: done
2025-01-09 00:23:47.675239 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-01-09 00:23:47.69334 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:23:50.355755 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:23:50.357807 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000001/logs/progress.log
2025-01-09 00:23:52.880651 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2025-01-09 00:23:52.882755 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000002/logs/progress.log
2025-01-09 00:23:55.401195 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2025-01-09 00:23:55.403508 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000003/logs/progress.log
2025-01-09 00:23:57.920776 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2025-01-09 00:23:57.923984 DEBUG::tools.R/processChunks: done
2025-01-09 00:23:57.926027 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-01-09 00:23:57.941871 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.counts_exon.tab
2025-01-09 00:23:57.955212 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.counts_exon_disjoint.tab
2025-01-09 00:23:57.963833 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.counts_gene.tab
2025-01-09 00:23:57.970719 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.counts_gene_coding.tab
2025-01-09 00:23:57.977371 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.counts_gene_exonic.tab
2025-01-09 00:23:57.984242 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.counts_intergenic.tab
2025-01-09 00:23:57.995369 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.counts_intron.tab
2025-01-09 00:23:57.998919 INFO::countGenomicFeatures.R/mergeCounts: done
2025-01-09 00:23:58.005995 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.summary_counts.tab
2025-01-09 00:23:58.008211 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-01-09 00:23:58.360135 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-01-09 00:23:58.361396 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-01-09 00:23:58.4435 INFO::coverage.R/calculateCoverage: starting...
2025-01-09 00:23:58.447764 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:24:01.180164 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:24:01.182293 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000001/logs/progress.log
2025-01-09 00:24:03.378522 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2025-01-09 00:24:03.3807 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000002/logs/progress.log
2025-01-09 00:24:05.579522 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2025-01-09 00:24:05.581765 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/chunks/chunk_000003/logs/progress.log
2025-01-09 00:24:07.777884 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2025-01-09 00:24:07.783103 DEBUG::tools.R/processChunks: done
2025-01-09 00:24:09.242095 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.coverage.RData
2025-01-09 00:24:09.244313 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.coverage.bw
2025-01-09 00:24:09.263059 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.summary_coverage.tab
2025-01-09 00:24:09.264895 INFO::coverage.R/calculateCoverage: done
2025-01-09 00:24:09.26704 INFO::analyzeVariants/analyzeVariants: starting ...
2025-01-09 00:24:09.35459 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:24:12.340918 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:24:12.445246 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:24:12.469038 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:24:12.470811 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.raw_variants.RData
2025-01-09 00:24:12.472955 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.filtered_variants.RData
2025-01-09 00:24:12.474766 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-09 00:24:12.476257 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-09 00:24:12.771355 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-09 00:24:12.903015 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/results/test_pe.summary_variants.tab
2025-01-09 00:24:12.905508 INFO::analyzeVariants/analyzeVariants: done
2025-01-09 00:24:12.909173 INFO::Pipeline run successful.
2025-01-09 00:24:13.087919 INFO::mergeLanes.R/doMergeLanes: starting...
2025-01-09 00:24:13.09276 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:24:13.095516 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.adapter_contaminated_1.RData
2025-01-09 00:24:13.099015 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-09 00:24:13.101619 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.adapter_contaminated_2.RData
2025-01-09 00:24:13.11503 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-09 00:24:13.117913 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.summary_preprocess.tab
2025-01-09 00:24:13.120683 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 "T" 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 "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-09 00:24:13.441281 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-09 00:24:13.449954 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.summary_alignment.tab
2025-01-09 00:24:13.459998 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.summary_analyzed_bamstats.tab
2025-01-09 00:24:13.462631 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-09 00:24:13.725039 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.summary_target_lengths.tab
2025-01-09 00:24:13.787228 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-09 00:24:13.825776 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-01-09 00:24:13.847389 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.counts_exon.tab
2025-01-09 00:24:13.86201 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.counts_exon_disjoint.tab
2025-01-09 00:24:13.870971 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.counts_gene.tab
2025-01-09 00:24:13.878354 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.counts_gene_coding.tab
2025-01-09 00:24:13.8856 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.counts_gene_exonic.tab
2025-01-09 00:24:13.893903 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.counts_intergenic.tab
2025-01-09 00:24:13.909043 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.counts_intron.tab
2025-01-09 00:24:13.91312 INFO::countGenomicFeatures.R/mergeCounts: done
2025-01-09 00:24:13.921374 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.summary_counts.tab
2025-01-09 00:24:13.923818 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-01-09 00:24:14.208745 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-01-09 00:24:16.421823 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.coverage.RData
2025-01-09 00:24:16.425262 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.coverage.bw
2025-01-09 00:24:16.442286 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.summary_coverage.tab
2025-01-09 00:24:16.485132 INFO::analyzeVariants/analyzeVariants: starting ...
2025-01-09 00:24:16.564132 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:24:19.623448 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:24:19.725997 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:24:19.748969 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:24:19.750822 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.raw_variants.RData
2025-01-09 00:24:19.752968 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.filtered_variants.RData
2025-01-09 00:24:19.754663 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-09 00:24:19.755991 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-09 00:24:20.061477 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-09 00:24:20.195202 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.mergeLanes.3b1c294375b47b/merged/results/merged.summary_variants.tab
2025-01-09 00:24:20.197783 INFO::analyzeVariants/analyzeVariants: done
2025-01-09 00:24:20.201035 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:24:20.54018 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-09 00:24:20.559024 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:24:20.576298 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-09 00:24:20.579284 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:24:23.338172 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:24:23.34015 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/chunks/chunk_000001/logs/progress.log
2025-01-09 00:24:26.034278 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-01-09 00:24:26.080072 DEBUG::tools.R/processChunks: done
2025-01-09 00:24:26.083008 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:24:26.085237 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/results/test_pe.adapter_contaminated_1.RData
2025-01-09 00:24:26.087671 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-09 00:24:26.089786 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/results/test_pe.adapter_contaminated_2.RData
2025-01-09 00:24:26.098191 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-09 00:24:26.100796 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/results/test_pe.summary_preprocess.tab
2025-01-09 00:24:26.103496 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/bams/processed.aligner_input_1.fastq ...
2025-01-09 00:24:26.109097 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/bams/processed.aligner_input_2.fastq ...
2025-01-09 00:24:26.114674 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/reports/shortReadReport_1 ...
2025-01-09 00:24:27.803175 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.3b1c2966e31c22/reports/shortReadReport_2 ...
2025-01-09 00:24:29.16812 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:24:29.460433 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-09 00:24:29.467124 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:24:29.471781 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-01-09 00:24:29.4752 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:24:32.235485 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:24:32.237461 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/chunks/chunk_000001/logs/progress.log
2025-01-09 00:24:34.927437 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-01-09 00:24:34.929417 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/chunks/chunk_000002/logs/progress.log
2025-01-09 00:24:37.623617 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-01-09 00:24:37.625598 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/chunks/chunk_000003/logs/progress.log
2025-01-09 00:24:40.299146 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-01-09 00:24:40.343328 DEBUG::tools.R/processChunks: done
2025-01-09 00:24:40.347008 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:24:40.349567 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/results/test_pe.adapter_contaminated_1.RData
2025-01-09 00:24:40.352864 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-09 00:24:40.355331 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/results/test_pe.adapter_contaminated_2.RData
2025-01-09 00:24:40.366513 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-09 00:24:40.369166 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/results/test_pe.summary_preprocess.tab
2025-01-09 00:24:40.372742 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/bams/processed.aligner_input_1.fastq ...
2025-01-09 00:24:40.379108 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/bams/processed.aligner_input_2.fastq ...
2025-01-09 00:24:40.384432 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/reports/shortReadReport_1 ...
2025-01-09 00:24:42.119629 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads.minichunks.3b1c29423ed9da/reports/shortReadReport_2 ...
2025-01-09 00:24:43.50962 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:24:43.796889 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-09 00:24:43.816298 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-01-09 00:24:43.819242 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:24:46.601431 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:24:46.603395 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads_single_end.3b1c2954189a95/chunks/chunk_000001/logs/progress.log
2025-01-09 00:24:49.01957 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2025-01-09 00:24:49.032717 DEBUG::tools.R/processChunks: done
2025-01-09 00:24:49.035801 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:24:49.03813 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads_single_end.3b1c2954189a95/results/test_se.adapter_contaminated_1.RData
2025-01-09 00:24:49.047111 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-01-09 00:24:49.049744 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads_single_end.3b1c2954189a95/results/test_se.summary_preprocess.tab
2025-01-09 00:24:49.052534 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads_single_end.3b1c2954189a95/bams/processed.aligner_input_1.fastq ...
2025-01-09 00:24:49.058296 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpE5zeW8/test.preprocessReads_single_end.3b1c2954189a95/reports/shortReadReport_1 ...
2025-01-09 00:24:50.873692 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/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:24:51.614779 INFO::preprocessReads.R/preprocessReads: starting...
2025-01-09 00:24:51.633357 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2025-01-09 00:24:51.651619 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2025-01-09 00:24:51.654506 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:24:54.500672 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:24:54.502849 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-01-09 00:24:57.414999 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2025-01-09 00:24:57.467279 DEBUG::tools.R/processChunks: done
2025-01-09 00:24:57.470628 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-01-09 00:24:57.473063 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2025-01-09 00:24:57.475772 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-01-09 00:24:57.478059 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2025-01-09 00:24:57.487369 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2500 highqual_reads=2500 adapter_contam=0 read_length=100 rRNA_contam_reads=0 processed_reads=2500 input_min_read_length=100 input_max_read_length=100 processed_min_read_length=71 processed_max_read_length=100
2025-01-09 00:24:57.489985 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2025-01-09 00:24:57.492816 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2025-01-09 00:24:57.499354 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2025-01-09 00:24:57.505286 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2025-01-09 00:25:00.837355 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2025-01-09 00:25:02.562116 INFO::preprocessReads.R/preprocessReads: done
2025-01-09 00:25:02.640471 INFO::alignReads.R/alignReads: starting alignment...
2025-01-09 00:25:02.645105 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:25:05.547264 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:25:05.549298 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" 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 "HISEQ1:109:D093LACXX:4:1206:17367:135118" 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 "HISEQ1:109:D093LACXX:4:1304:1838:53573" 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 "HISEQ1:109:D093LACXX:4:2303:2956:116587" 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 "M" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" 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 "T" on read "HISEQ1:109:D093LACXX:4:1206:20028:108227" 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 "T" on read "HISEQ1:109:D093LACXX:4:1207:19518:143960" 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 "T" on read "HISEQ1:109:D093LACXX:4:2207:4065:173048" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-01-09 00:25:10.863398 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.089 minutes
2025-01-09 00:25:10.871429 DEBUG::tools.R/processChunks: done
2025-01-09 00:25:10.873582 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2025-01-09 00:25:10.908952 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-01-09 00:25:10.917589 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2025-01-09 00:25:10.925105 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2025-01-09 00:25:10.928062 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-01-09 00:25:11.122825 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2025-01-09 00:25:11.185356 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-01-09 00:25:11.186804 INFO::alignReads.R/alignReads: done
2025-01-09 00:25:11.266823 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-01-09 00:25:11.283862 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:25:14.127728 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:25:14.129678 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-01-09 00:25:16.713919 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-01-09 00:25:16.717013 DEBUG::tools.R/processChunks: done
2025-01-09 00:25:16.718974 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-01-09 00:25:16.729854 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2025-01-09 00:25:16.739189 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2025-01-09 00:25:16.746 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2025-01-09 00:25:16.75088 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2025-01-09 00:25:16.75563 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2025-01-09 00:25:16.760404 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2025-01-09 00:25:16.767638 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2025-01-09 00:25:16.771409 INFO::countGenomicFeatures.R/mergeCounts: done
2025-01-09 00:25:16.775843 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2025-01-09 00:25:16.777999 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-01-09 00:25:17.047616 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-01-09 00:25:17.048903 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-01-09 00:25:17.125817 INFO::coverage.R/calculateCoverage: starting...
2025-01-09 00:25:17.130137 DEBUG::tools.R/processChunks: starting...
2025-01-09 00:25:20.371642 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-01-09 00:25:20.37369 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2025-01-09 00:25:22.700013 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2025-01-09 00:25:22.703116 DEBUG::tools.R/processChunks: done
2025-01-09 00:25:24.165993 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2025-01-09 00:25:24.167879 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2025-01-09 00:25:24.248504 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2025-01-09 00:25:24.250156 INFO::coverage.R/calculateCoverage: done
2025-01-09 00:25:24.251859 INFO::analyzeVariants/analyzeVariants: starting ...
2025-01-09 00:25:24.350206 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-01-09 00:25:36.525948 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-01-09 00:25:36.641237 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-01-09 00:25:36.667313 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-01-09 00:25:36.669316 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2025-01-09 00:25:36.672634 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2025-01-09 00:25:36.674671 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-01-09 00:25:36.676216 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-01-09 00:25:37.012172 INFO::analyzeVariants.R/writeVCF: ...done
2025-01-09 00:25:37.164472 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2025-01-09 00:25:37.167615 INFO::analyzeVariants/analyzeVariants: done
2025-01-09 00:25:37.172714 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpE5zeW8/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/config/default-config.txt 
2025-01-09 00:25:37.445943 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpE5zeW8/test.calcTargetLengths.3b1c292d9a5de4/results/test_pe.summary_target_lengths.tab
 done successfully.



Executing test function test.sclapply  ...  done successfully.



Executing test function test.tryKeepTraceback  ...  done successfully.



Executing test function test.truncateReads  ...  done successfully.



Executing test function test.truncateReads.trim5  ...  done successfully.

RUNIT TEST PROTOCOL -- Thu Jan  9 00:25:52 2025 
*********************************************** 
Number of test functions: 61 
Number of deactivated test functions: 10 
Number of errors: 0 
Number of failures: 0 

 
1 Test Suite : 
HTSeqGenie unit testing - 61 test functions, 0 errors, 0 failures



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (26.42 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (16.94 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.5 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (93.28 seconds)
test.wrap.callVariants: (4 checks) ... OK (11.58 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (23.85 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (3.9 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.19 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (2.03 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (30.15 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (28.49 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.85 seconds)
test.isSparse: (5 checks) ... OK (0.11 seconds)
test.mergeCoverage: (1 checks) ... OK (1.26 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.03 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.19 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.38 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.42 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.04 seconds)
test.isAdapter: (5 checks) ... OK (0.14 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.1 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.3 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.43 seconds)
test.getRRNAIds: (1 checks) ... OK (0.27 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.17 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.07 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.06 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.04 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.gatk.R 
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.19 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.22 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.41 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.19 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.21 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.7 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.17 seconds)
test.getObjectFilename: (4 checks) ... OK (0.01 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.2 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (57.85 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.picard.R 
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (8.91 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (14.34 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (7.36 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.12 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.14 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.14 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (45.84 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.27 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (14.99 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.2/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.08 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.26 seconds) 

runTests.R: OK !
There were 50 or more warnings (use warnings() to see the first 50)
> 
> proc.time()
   user  system elapsed 
274.777  93.986 413.772

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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