##############################################################################
##############################################################################
###
### 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.3 (2025-02-28)
* using platform: aarch64-unknown-linux-gnu
* R was compiled by
    aarch64-unknown-linux-gnu-gcc (GCC) 14.2.0
    GNU Fortran (GCC) 14.2.0
* 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’

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


* installing to library ‘/home/biocbuild/R/R-4.4.3/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)

R version 4.4.3 (2025-02-28) -- "Trophy Case"
Copyright (C) 2025 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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:39:45.378895 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-18 08:39:45.389304 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:39:45.395012 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-18 08:39:45.398125 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:39:48.226314 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:39:48.228303 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/chunks/chunk_000001/logs/progress.log
2025-03-18 08:39:51.106556 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2025-03-18 08:39:51.108585 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/chunks/chunk_000002/logs/progress.log
2025-03-18 08:39:53.939781 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2025-03-18 08:39:53.941768 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/chunks/chunk_000003/logs/progress.log
2025-03-18 08:39:56.813013 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2025-03-18 08:39:56.854148 DEBUG::tools.R/processChunks: done
2025-03-18 08:39:56.859434 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-18 08:39:56.862737 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/results/test_pe.adapter_contaminated_1.RData
2025-03-18 08:39:56.866847 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-18 08:39:56.869524 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/results/test_pe.adapter_contaminated_2.RData
2025-03-18 08:39:56.882971 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-18 08:39:56.886168 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/results/test_pe.summary_preprocess.tab
2025-03-18 08:39:56.890924 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/bams/processed.aligner_input_1.fastq ...
2025-03-18 08:39:56.897578 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/bams/processed.aligner_input_2.fastq ...
2025-03-18 08:39:56.903436 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/reports/shortReadReport_1 ...
2025-03-18 08:39:58.922302 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/reports/shortReadReport_2 ...
2025-03-18 08:40:00.684409 INFO::preprocessReads.R/preprocessReads: done
2025-03-18 08:40:00.741252 INFO::alignReads.R/alignReads: starting alignment...
2025-03-18 08:40:00.747264 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:40:03.331429 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:40:03.333544 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/chunks/chunk_000001/logs/progress.log
2025-03-18 08:40:06.472256 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2025-03-18 08:40:06.474575 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/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-03-18 08:40:09.196529 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2025-03-18 08:40:09.19895 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-18 08:40:11.950706 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2025-03-18 08:40:11.954089 DEBUG::tools.R/processChunks: done
2025-03-18 08:40:11.955899 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-03-18 08:40:12.274247 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-18 08:40:12.285954 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/results/test_pe.summary_alignment.tab
2025-03-18 08:40:12.296437 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/results/test_pe.summary_analyzed_bamstats.tab
2025-03-18 08:40:12.298872 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-18 08:40:12.582082 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.30c8f07dbc7c53/results/test_pe.summary_target_lengths.tab
2025-03-18 08:40:12.642632 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-18 08:40:12.643911 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:40:12.951177 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-18 08:40:12.954513 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:40:13.032418 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2025-03-18 08:40:13.039433 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:40:13.044151 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-18 08:40:13.046847 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:40:16.527596 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:40:16.529926 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/chunks/chunk_000001/logs/progress.log
2025-03-18 08:40:19.381659 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2025-03-18 08:40:19.383554 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/chunks/chunk_000002/logs/progress.log
2025-03-18 08:40:22.174339 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2025-03-18 08:40:22.176186 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/chunks/chunk_000003/logs/progress.log
2025-03-18 08:40:25.035763 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2025-03-18 08:40:25.037691 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/chunks/chunk_000004/logs/progress.log
2025-03-18 08:40:27.796409 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.046 minutes
2025-03-18 08:40:27.835064 DEBUG::tools.R/processChunks: done
2025-03-18 08:40:27.839867 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-18 08:40:27.843384 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/results/test_pe.adapter_contaminated_1.RData
2025-03-18 08:40:27.84785 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-18 08:40:27.850647 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/results/test_pe.adapter_contaminated_2.RData
2025-03-18 08:40:27.864932 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-18 08:40:27.867991 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/results/test_pe.summary_preprocess.tab
2025-03-18 08:40:27.872846 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/bams/processed.aligner_input_1.fastq ...
2025-03-18 08:40:27.879772 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/bams/processed.aligner_input_2.fastq ...
2025-03-18 08:40:27.885397 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/reports/shortReadReport_1 ...
2025-03-18 08:40:29.671283 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReads.sparsechunks.30c8f01f974e92/reports/shortReadReport_2 ...
2025-03-18 08:40:31.100847 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:40:31.329309 INFO::alignReads.R/alignReadsChunk: running gsnap...
2025-03-18 08:40:31.335656 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/RtmpTIjUb1/test.alignReadsOneSingleEnd.30c8f013fb0bea/bams/test.alignReads /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2025-03-18 08:40:31.45386 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2025-03-18 08:40:31.600067 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReadsOneSingleEnd.30c8f013fb0bea/results/test.alignReads.summary_alignment.tab
2025-03-18 08:40:31.652706 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.alignReadsOneSingleEnd.30c8f013fb0bea/results/test.alignReads.summary_analyzed_bamstats.tab
2025-03-18 08:40:31.654886 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.003 0 0.004
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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:40:32.07232 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.genotype.30c8f042be616/results/test_pe.coverage.RData
2025-03-18 08:40:32.075163 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.genotype.30c8f042be616/results/test_pe.coverage.bw
2025-03-18 08:40:32.23362 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.genotype.30c8f042be616/results/test_pe.summary_coverage.tab
2025-03-18 08:40:32.236063 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-18 08:40:43.847267 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-18 08:40:43.974785 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-18 08:40:44.001732 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-18 08:40:44.003872 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.genotype.30c8f042be616/results/test_pe.raw_variants.RData
2025-03-18 08:40:44.007108 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.genotype.30c8f042be616/results/test_pe.filtered_variants.RData
2025-03-18 08:40:44.009092 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-18 08:40:44.010879 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-18 08:40:44.609787 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-18 08:40:44.611464 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2025-03-18 08:42:10.879081 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-18 08:42:11.438623 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-18 08:42:11.439781 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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:42:12.017504 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-18 08:42:23.610564 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-18 08:42:23.722045 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-18 08:42:23.745768 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-18 08:42:23.7477 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.30c8f04b5d71e2/results/test_pe.raw_variants.RData
2025-03-18 08:42:23.750715 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.30c8f04b5d71e2/results/test_pe.filtered_variants.RData
2025-03-18 08:42:23.75251 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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:42:23.94016 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-18 08:42:35.404818 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-18 08:42:35.495126 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-18 08:42:35.521491 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-18 08:42:35.523552 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.filters.30c8f05a33c080/results/test_pe.raw_variants.RData
2025-03-18 08:42:35.527119 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.filters.30c8f05a33c080/results/test_pe.filtered_variants.RData
2025-03-18 08:42:35.529183 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-18 08:42:35.531392 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-18 08:42:46.92568 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-18 08:42:46.9861 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-18 08:42:47.012501 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-18 08:42:47.01455 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.filters.30c8f05a33c080/results/test_pe.raw_variants.RData
2025-03-18 08:42:47.017983 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.filters.30c8f05a33c080/results/test_pe.filtered_variants.RData
2025-03-18 08:42:47.0208 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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:42:47.337161 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-18 08:42:47.339277 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2025-03-18 08:42:50.373053 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-18 08:42:50.492404 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-18 08:42:50.518045 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-18 08:42:50.520004 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.which.30c8f010850f47/results/test_pe.raw_variants.RData
2025-03-18 08:42:50.522657 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.wrap.callVariants.which.30c8f010850f47/results/test_pe.filtered_variants.RData
2025-03-18 08:42:50.524536 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:42:50.717425 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-18 08:42:50.719262 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:42:52.472022 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-18 08:42:52.78319 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



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



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



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



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



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



Executing test function test.mergeCoverage  ... 2025-03-18 08:43:59.296051 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/mplfbsey/merged/results/bla.coverage.RData
2025-03-18 08:43:59.299613 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpTIjUb1/mplfbsey/merged/results/bla.coverage.bw
2025-03-18 08:43:59.383185 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/mplfbsey/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2025-03-18 08:44:00.337547 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/hnvcbqyk/merged/results/bla.coverage.RData
2025-03-18 08:44:00.33955 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpTIjUb1/hnvcbqyk/merged/results/bla.coverage.bw
2025-03-18 08:44:00.353472 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/hnvcbqyk/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:01.846019 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-18 08:44:01.8475 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpTIjUb1/test.detectRRNA.30c8f011f41ccc/bams/rRNA_contam/input1.fastq
2025-03-18 08:44:01.851906 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/RtmpTIjUb1/test.detectRRNA.30c8f011f41ccc/bams/rRNA_contam/test_se /home/biocbuild/tmp/RtmpTIjUb1/test.detectRRNA.30c8f011f41ccc/bams/rRNA_contam/input1.fastq 2>&1
2025-03-18 08:44:01.971073 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-18 08:44:01.972447 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:02.125874 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2025-03-18 08:44:02.127213 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpTIjUb1/test.detectRRNA.paired_end.30c8f04fe90224/bams/rRNA_contam/input1.fastq
2025-03-18 08:44:02.129269 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpTIjUb1/test.detectRRNA.paired_end.30c8f04fe90224/bams/rRNA_contam/input2.fastq
2025-03-18 08:44:02.132357 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/RtmpTIjUb1/test.detectRRNA.paired_end.30c8f04fe90224/bams/rRNA_contam/test_pe /home/biocbuild/tmp/RtmpTIjUb1/test.detectRRNA.paired_end.30c8f04fe90224/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/tmp/RtmpTIjUb1/test.detectRRNA.paired_end.30c8f04fe90224/bams/rRNA_contam/input2.fastq 2>&1
2025-03-18 08:44:02.39069 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2025-03-18 08:44:02.392024 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2025-03-18 08:44:02.419369 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/RtmpTIjUb1/test_get_rRNA_idsfwzaipth/test_pe /home/biocbuild/tmp/RtmpTIjUb1/test_get_rRNA_idsfwzaipth/1.fastq -a paired /home/biocbuild/tmp/RtmpTIjUb1/test_get_rRNA_idsfwzaipth/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2025-03-18 08:44:02.734516 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/RtmpTIjUb1/test_get_rRNAIds_randomubodyqzm/test_pe /home/biocbuild/tmp/RtmpTIjUb1/test_get_rRNAIds_randomubodyqzm/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2025-03-18 08:44:02.880687 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-18 08:44:02.882629 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2025-03-18 08:44:02.883842 INFO::filterQuality.R/filterByLength: done
2025-03-18 08:44:02.948349 INFO::filterQuality.R/filterQuality: filterByLength...
2025-03-18 08:44:02.94959 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2025-03-18 08:44:02.950798 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2025-03-18 08:44:03.022871 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-18 08:44:03.035173 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-18 08:44:03.036656 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-18 08:44:03.043014 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-18 08:44:03.044452 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-18 08:44:03.050803 INFO::preprocessReads.R/preprocessReadsChunk: done
2025-03-18 08:44:03.052238 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2025-03-18 08:44:03.058565 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



Executing test function test.realignIndelsGATK.parallel  ... Timing stopped at: 0 0 0
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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:03.406285 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:03.40942 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:03.624693 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:03.714943 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-18 08:44:03.718709 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:03.721799 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:03.966825 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:04.142872 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:04.314397 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:04.370469 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-18 08:44:04.374002 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:04.377206 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:04.610268 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:04.664068 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2025-03-18 08:44:04.667572 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:04.670759 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/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/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:44:05.458371 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-18 08:44:05.465134 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:44:05.470035 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-18 08:44:05.473008 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:44:08.3441 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:44:08.346273 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000001/logs/progress.log
2025-03-18 08:44:11.003259 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-03-18 08:44:11.00536 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000002/logs/progress.log
2025-03-18 08:44:13.651283 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-18 08:44:13.653284 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000003/logs/progress.log
2025-03-18 08:44:16.338614 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-18 08:44:16.389779 DEBUG::tools.R/processChunks: done
2025-03-18 08:44:16.393336 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-18 08:44:16.395567 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.adapter_contaminated_1.RData
2025-03-18 08:44:16.398407 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-18 08:44:16.400504 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.adapter_contaminated_2.RData
2025-03-18 08:44:16.411112 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-18 08:44:16.413817 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.summary_preprocess.tab
2025-03-18 08:44:16.417386 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/bams/processed.aligner_input_1.fastq ...
2025-03-18 08:44:16.424036 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/bams/processed.aligner_input_2.fastq ...
2025-03-18 08:44:16.429702 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/reports/shortReadReport_1 ...
2025-03-18 08:44:18.19644 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/reports/shortReadReport_2 ...
2025-03-18 08:44:19.791793 INFO::preprocessReads.R/preprocessReads: done
2025-03-18 08:44:19.863704 INFO::alignReads.R/alignReads: starting alignment...
2025-03-18 08:44:19.868366 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:44:22.381092 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:44:22.383269 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000001/logs/progress.log
2025-03-18 08:44:25.030396 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-03-18 08:44:25.032562 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/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-03-18 08:44:27.619861 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2025-03-18 08:44:27.622094 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2025-03-18 08:44:30.222668 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2025-03-18 08:44:30.226095 DEBUG::tools.R/processChunks: done
2025-03-18 08:44:30.228027 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-03-18 08:44:30.518926 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-18 08:44:30.528956 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.summary_alignment.tab
2025-03-18 08:44:30.538513 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.summary_analyzed_bamstats.tab
2025-03-18 08:44:30.541016 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-18 08:44:30.789843 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.summary_target_lengths.tab
2025-03-18 08:44:30.8506 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-18 08:44:30.851995 INFO::alignReads.R/alignReads: done
2025-03-18 08:44:30.926731 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2025-03-18 08:44:30.947874 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:44:33.769682 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:44:33.771974 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000001/logs/progress.log
2025-03-18 08:44:36.359117 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2025-03-18 08:44:36.361466 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000002/logs/progress.log
2025-03-18 08:44:38.905112 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2025-03-18 08:44:38.907243 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000003/logs/progress.log
2025-03-18 08:44:41.457162 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2025-03-18 08:44:41.460431 DEBUG::tools.R/processChunks: done
2025-03-18 08:44:41.462593 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-18 08:44:41.479225 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.counts_exon.tab
2025-03-18 08:44:41.492586 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.counts_exon_disjoint.tab
2025-03-18 08:44:41.501543 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.counts_gene.tab
2025-03-18 08:44:41.508592 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.counts_gene_coding.tab
2025-03-18 08:44:41.515685 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.counts_gene_exonic.tab
2025-03-18 08:44:41.523053 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.counts_intergenic.tab
2025-03-18 08:44:41.534513 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.counts_intron.tab
2025-03-18 08:44:41.538116 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-18 08:44:41.545464 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.summary_counts.tab
2025-03-18 08:44:41.547761 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-18 08:44:41.903244 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-18 08:44:41.904482 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2025-03-18 08:44:41.985999 INFO::coverage.R/calculateCoverage: starting...
2025-03-18 08:44:41.990263 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:44:44.738951 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:44:44.741151 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000001/logs/progress.log
2025-03-18 08:44:46.950389 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2025-03-18 08:44:46.952643 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000002/logs/progress.log
2025-03-18 08:44:49.149469 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2025-03-18 08:44:49.151926 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/chunks/chunk_000003/logs/progress.log
2025-03-18 08:44:51.348302 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2025-03-18 08:44:51.351877 DEBUG::tools.R/processChunks: done
2025-03-18 08:44:53.020581 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.coverage.RData
2025-03-18 08:44:53.022794 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.coverage.bw
2025-03-18 08:44:53.039992 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.summary_coverage.tab
2025-03-18 08:44:53.042042 INFO::coverage.R/calculateCoverage: done
2025-03-18 08:44:53.044534 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-18 08:44:53.123167 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-18 08:44:56.186357 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-18 08:44:56.29883 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-18 08:44:56.323169 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-18 08:44:56.325012 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.raw_variants.RData
2025-03-18 08:44:56.327392 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.filtered_variants.RData
2025-03-18 08:44:56.32918 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-18 08:44:56.330652 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-18 08:44:56.66057 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-18 08:44:56.815198 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/results/test_pe.summary_variants.tab
2025-03-18 08:44:56.818125 INFO::analyzeVariants/analyzeVariants: done
2025-03-18 08:44:56.826151 INFO::Pipeline run successful.
2025-03-18 08:44:57.085289 INFO::mergeLanes.R/doMergeLanes: starting...
2025-03-18 08:44:57.091576 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-18 08:44:57.095133 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.adapter_contaminated_1.RData
2025-03-18 08:44:57.099606 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-18 08:44:57.103076 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.adapter_contaminated_2.RData
2025-03-18 08:44:57.119473 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-18 08:44:57.123243 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.summary_preprocess.tab
2025-03-18 08:44:57.126646 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-03-18 08:44:57.481453 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2025-03-18 08:44:57.490909 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.summary_alignment.tab
2025-03-18 08:44:57.501611 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.summary_analyzed_bamstats.tab
2025-03-18 08:44:57.504464 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2025-03-18 08:44:57.778275 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.summary_target_lengths.tab
2025-03-18 08:44:57.846445 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2025-03-18 08:44:57.887625 INFO::countGenomicFeatures.R/mergeCounts: starting...
2025-03-18 08:44:57.911826 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.counts_exon.tab
2025-03-18 08:44:57.927833 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.counts_exon_disjoint.tab
2025-03-18 08:44:57.937959 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.counts_gene.tab
2025-03-18 08:44:57.946595 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.counts_gene_coding.tab
2025-03-18 08:44:57.955195 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.counts_gene_exonic.tab
2025-03-18 08:44:57.963779 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.counts_intergenic.tab
2025-03-18 08:44:57.979291 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.counts_intron.tab
2025-03-18 08:44:57.98319 INFO::countGenomicFeatures.R/mergeCounts: done
2025-03-18 08:44:57.992211 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.summary_counts.tab
2025-03-18 08:44:57.994858 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2025-03-18 08:44:58.290908 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2025-03-18 08:45:00.105463 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.coverage.RData
2025-03-18 08:45:00.108118 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.coverage.bw
2025-03-18 08:45:00.123227 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.summary_coverage.tab
2025-03-18 08:45:00.159207 INFO::analyzeVariants/analyzeVariants: starting ...
2025-03-18 08:45:00.234513 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2025-03-18 08:45:03.225641 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2025-03-18 08:45:03.334393 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2025-03-18 08:45:03.358423 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2025-03-18 08:45:03.360353 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.raw_variants.RData
2025-03-18 08:45:03.362728 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.filtered_variants.RData
2025-03-18 08:45:03.364525 INFO::analyzeVariants.R/wrap.callVariants: ...done
2025-03-18 08:45:03.366066 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2025-03-18 08:45:03.67533 INFO::analyzeVariants.R/writeVCF: ...done
2025-03-18 08:45:03.81095 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.mergeLanes.30c8f0a4b0be8/merged/results/merged.summary_variants.tab
2025-03-18 08:45:03.813547 INFO::analyzeVariants/analyzeVariants: done
2025-03-18 08:45:03.816708 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:45:04.101663 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-18 08:45:04.108274 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:45:04.112762 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-18 08:45:04.115658 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:45:06.740295 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:45:06.74238 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/chunks/chunk_000001/logs/progress.log
2025-03-18 08:45:09.450408 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2025-03-18 08:45:09.50163 DEBUG::tools.R/processChunks: done
2025-03-18 08:45:09.504642 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-18 08:45:09.506869 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/results/test_pe.adapter_contaminated_1.RData
2025-03-18 08:45:09.509196 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-18 08:45:09.511265 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/results/test_pe.adapter_contaminated_2.RData
2025-03-18 08:45:09.519627 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-18 08:45:09.522282 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/results/test_pe.summary_preprocess.tab
2025-03-18 08:45:09.525342 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/bams/processed.aligner_input_1.fastq ...
2025-03-18 08:45:09.531542 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/bams/processed.aligner_input_2.fastq ...
2025-03-18 08:45:09.537641 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/reports/shortReadReport_1 ...
2025-03-18 08:45:11.377429 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.30c8f01a10b36c/reports/shortReadReport_2 ...
2025-03-18 08:45:12.855497 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:45:13.159774 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-18 08:45:13.166528 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:45:13.171551 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2025-03-18 08:45:13.174449 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:45:15.764365 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2025-03-18 08:45:15.766477 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/chunks/chunk_000001/logs/progress.log
2025-03-18 08:45:18.43262 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2025-03-18 08:45:18.434629 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/chunks/chunk_000002/logs/progress.log
2025-03-18 08:45:21.092619 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2025-03-18 08:45:21.09473 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/chunks/chunk_000003/logs/progress.log
2025-03-18 08:45:23.77438 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2025-03-18 08:45:23.823482 DEBUG::tools.R/processChunks: done
2025-03-18 08:45:23.827112 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2025-03-18 08:45:23.82945 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/results/test_pe.adapter_contaminated_1.RData
2025-03-18 08:45:23.83252 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2025-03-18 08:45:23.834847 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/results/test_pe.adapter_contaminated_2.RData
2025-03-18 08:45:23.845634 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2025-03-18 08:45:23.84835 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/results/test_pe.summary_preprocess.tab
2025-03-18 08:45:23.851958 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/bams/processed.aligner_input_1.fastq ...
2025-03-18 08:45:23.858783 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/bams/processed.aligner_input_2.fastq ...
2025-03-18 08:45:23.864298 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/reports/shortReadReport_1 ...
2025-03-18 08:45:25.633031 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpTIjUb1/test.preprocessReads.minichunks.30c8f071c30ca6/reports/shortReadReport_2 ...
2025-03-18 08:45:27.07504 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpTIjUb1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/config/default-config.txt 
2025-03-18 08:45:27.327132 INFO::preprocessReads.R/preprocessReads: starting...
2025-03-18 08:45:27.3334 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.3/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2025-03-18 08:45:27.336197 DEBUG::tools.R/processChunks: starting...
2025-03-18 08:46:27.358603 DEBUG::tools.R/traceMem: wired.mem=-17.659945 GiB
2025-03-18 08:47:27.409813 DEBUG::tools.R/traceMem: wired.mem=-18.540634 GiB
2025-03-18 08:48:27.473573 DEBUG::tools.R/traceMem: wired.mem=-19.586433 GiB
2025-03-18 08:49:27.537846 DEBUG::tools.R/traceMem: wired.mem=-22.446432 GiB
2025-03-18 08:50:27.601636 DEBUG::tools.R/traceMem: wired.mem=-17.949008 GiB
2025-03-18 08:51:27.665604 DEBUG::tools.R/traceMem: wired.mem=-13.412934 GiB
2025-03-18 08:52:27.729702 DEBUG::tools.R/traceMem: wired.mem=-14.765818 GiB
2025-03-18 08:53:27.794162 DEBUG::tools.R/traceMem: wired.mem=-11.449827 GiB
2025-03-18 08:54:27.860327 DEBUG::tools.R/traceMem: wired.mem=-12.012184 GiB
2025-03-18 08:55:27.925652 DEBUG::tools.R/traceMem: wired.mem=-12.272853 GiB
2025-03-18 08:56:27.993763 DEBUG::tools.R/traceMem: wired.mem=-24.289673 GiB
2025-03-18 08:57:28.057499 DEBUG::tools.R/traceMem: wired.mem=-24.976957 GiB
2025-03-18 08:58:28.121867 DEBUG::tools.R/traceMem: wired.mem=-19.597468 GiB
2025-03-18 08:59:28.18575 DEBUG::tools.R/traceMem: wired.mem=-12.736274 GiB
2025-03-18 09:00:28.249923 DEBUG::tools.R/traceMem: wired.mem=-16.502751 GiB
2025-03-18 09:01:28.31355 DEBUG::tools.R/traceMem: wired.mem=-26.253148 GiB
2025-03-18 09:02:28.38146 DEBUG::tools.R/traceMem: wired.mem=-17.104372 GiB
2025-03-18 09:03:28.445897 DEBUG::tools.R/traceMem: wired.mem=-19.384107 GiB
2025-03-18 09:04:28.509753 DEBUG::tools.R/traceMem: wired.mem=-26.258211 GiB
2025-03-18 09:05:28.573696 DEBUG::tools.R/traceMem: wired.mem=-23.400382 GiB
2025-03-18 09:06:28.637847 DEBUG::tools.R/traceMem: wired.mem=-14.936343 GiB
2025-03-18 09:07:28.701997 DEBUG::tools.R/traceMem: wired.mem=-17.275068 GiB
2025-03-18 09:08:28.765879 DEBUG::tools.R/traceMem: wired.mem=-13.054968 GiB
2025-03-18 09:09:28.829859 DEBUG::tools.R/traceMem: wired.mem=-16.466641 GiB
2025-03-18 09:10:28.896904 DEBUG::tools.R/traceMem: wired.mem=-14.926086 GiB
2025-03-18 09:11:28.961823 DEBUG::tools.R/traceMem: wired.mem=-17.199170 GiB
2025-03-18 09:12:29.025922 DEBUG::tools.R/traceMem: wired.mem=-26.520347 GiB