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

Hostname	OS	Arch (*)	R version	Installed pkgs
teran2	Linux (Ubuntu 24.04.1 LTS)	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4448
nebbiolo2	Linux (Ubuntu 22.04.3 LTS)	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4455
palomino8	Windows Server 2022 Datacenter	x64	4.4.1 (2024-06-14 ucrt) -- "Race for Your Life"	4453
lconway	macOS 12.7.1 Monterey	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4486
kjohnson3	macOS 13.6.5 Ventura	arm64	4.4.1 (2024-06-14) -- "Race for Your Life"	4433
kunpeng2	Linux (openEuler 22.03 LTS-SP1)	aarch64	4.4.1 (2024-06-14) -- "Race for Your Life"	4432
Click on any hostname to see more info about the system (e.g. compilers) () as reported by 'uname -p', except on Windows and Mac OS X*

CHECK results for HTSeqGenie on nebbiolo2

To the developers/maintainers of the HTSeqGenie package:
- Allow up to 24 hours (and sometimes 48 hours) for your latest push to git@git.bioconductor.org:packages/HTSeqGenie.git to reflect on this report. See Troubleshooting Build Report for more information.
- Use the following Renviron settings to reproduce errors and warnings.
- If 'R CMD check' started to fail recently on the Linux builder(s) over a missing dependency, add the missing dependency to 'Suggests:' in your DESCRIPTION file. See Renviron.bioc for more information.

raw results

Summary

Package: HTSeqGenie

Version: 4.35.0

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

StartedAt: 2024-09-23 23:33:21 -0400 (Mon, 23 Sep 2024)

EndedAt: 2024-09-24 00:13:22 -0400 (Tue, 24 Sep 2024)

EllapsedTime: 2400.5 seconds

RetCode: None

Status: TIMEOUT

CheckDir: HTSeqGenie.Rcheck

Warnings: NA

Command output

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


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

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

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

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

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

Functions with \usage entries need to have the appropriate \alias
entries, and all their arguments documented.
The \usage entries must correspond to syntactically valid R code.
See chapter ‘Writing R documentation files’ in the ‘Writing R
Extensions’ manual.
* checking Rd contents ... OK
* checking for unstated dependencies in examples ... OK
* checking files in ‘vignettes’ ... OK
* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
  Running ‘doRUnit.R’

Installation output

HTSeqGenie.Rcheck/00install.out

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/bbs-3.20-bioc/R/bin/R CMD INSTALL HTSeqGenie
###
##############################################################################
##############################################################################


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

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.4.1 (2024-06-14) -- "Race for Your Life"
Copyright (C) 2024 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu

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

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

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

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

Attaching package: 'BiocGenerics'

The following objects are masked from 'package:stats':

    IQR, mad, sd, var, xtabs

The following objects are masked from 'package:base':

    Filter, Find, Map, Position, Reduce, anyDuplicated, aperm, append,
    as.data.frame, basename, cbind, colnames, dirname, do.call,
    duplicated, eval, evalq, get, grep, grepl, intersect, is.unsorted,
    lapply, mapply, match, mget, order, paste, pmax, pmax.int, pmin,
    pmin.int, rank, rbind, rownames, sapply, 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= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:38:57.661386 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-23 23:38:57.669869 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:38:57.673323 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-23 23:38:57.675463 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:39:00.533707 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:39:00.535182 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/chunks/chunk_000001/logs/progress.log
2024-09-23 23:39:03.249137 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-09-23 23:39:03.250648 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/chunks/chunk_000002/logs/progress.log
2024-09-23 23:39:05.946836 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-09-23 23:39:05.948232 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/chunks/chunk_000003/logs/progress.log
2024-09-23 23:39:08.718516 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-09-23 23:39:08.749082 DEBUG::tools.R/processChunks: done
2024-09-23 23:39:08.753211 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:39:08.755611 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/results/test_pe.adapter_contaminated_1.RData
2024-09-23 23:39:08.758645 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-23 23:39:08.760359 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/results/test_pe.adapter_contaminated_2.RData
2024-09-23 23:39:08.771647 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-09-23 23:39:08.774063 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/results/test_pe.summary_preprocess.tab
2024-09-23 23:39:08.777468 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/bams/processed.aligner_input_1.fastq ...
2024-09-23 23:39:08.782015 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/bams/processed.aligner_input_2.fastq ...
2024-09-23 23:39:08.786146 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/reports/shortReadReport_1 ...
2024-09-23 23:39:10.153376 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/reports/shortReadReport_2 ...
2024-09-23 23:39:11.306308 INFO::preprocessReads.R/preprocessReads: done
2024-09-23 23:39:11.370095 INFO::alignReads.R/alignReads: starting alignment...
2024-09-23 23:39:11.376626 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:39:14.641947 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:39:14.64355 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/chunks/chunk_000001/logs/progress.log
2024-09-23 23:39:17.539585 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2024-09-23 23:39:17.541483 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-23 23:39:20.198897 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-09-23 23:39:20.200814 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-23 23:39:22.863792 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-09-23 23:39:22.86625 DEBUG::tools.R/processChunks: done
2024-09-23 23:39:22.867674 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-23 23:39:23.085407 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-09-23 23:39:23.094041 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/results/test_pe.summary_alignment.tab
2024-09-23 23:39:23.101207 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/results/test_pe.summary_analyzed_bamstats.tab
2024-09-23 23:39:23.103068 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-09-23 23:39:23.361527 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.1bd9af1dd33ff3/results/test_pe.summary_target_lengths.tab
2024-09-23 23:39:23.410406 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-09-23 23:39:23.41147 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:39:23.704434 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-23 23:39:23.707941 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:39:23.788116 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-09-23 23:39:23.794019 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:39:23.797605 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-23 23:39:23.799919 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:39:27.000218 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:39:27.001589 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/chunks/chunk_000001/logs/progress.log
2024-09-23 23:39:29.701323 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-09-23 23:39:29.702679 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/chunks/chunk_000002/logs/progress.log
2024-09-23 23:39:32.407445 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-09-23 23:39:32.409255 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/chunks/chunk_000003/logs/progress.log
2024-09-23 23:39:35.168724 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-09-23 23:39:35.170176 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/chunks/chunk_000004/logs/progress.log
2024-09-23 23:39:37.855343 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2024-09-23 23:39:37.888501 DEBUG::tools.R/processChunks: done
2024-09-23 23:39:37.892699 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:39:37.895378 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/results/test_pe.adapter_contaminated_1.RData
2024-09-23 23:39:37.898579 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-23 23:39:37.900448 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/results/test_pe.adapter_contaminated_2.RData
2024-09-23 23:39:37.911433 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-09-23 23:39:37.913692 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/results/test_pe.summary_preprocess.tab
2024-09-23 23:39:37.917295 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/bams/processed.aligner_input_1.fastq ...
2024-09-23 23:39:37.921756 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/bams/processed.aligner_input_2.fastq ...
2024-09-23 23:39:37.92506 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/reports/shortReadReport_1 ...
2024-09-23 23:39:39.263097 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.alignReads.sparsechunks.1bd9af52ea4ab7/reports/shortReadReport_2 ...
2024-09-23 23:39:40.375165 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:39:40.552989 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-09-23 23:39:40.557461 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -D /home/biocbuild/.local/share/gmap -t 1 -d TP53_demo_3.2.2 --quality-protocol=illumina  -A sam --read-group-id=test_se -m 0 --split-output /tmp/Rtmp0futa1/test.alignReadsOneSingleEnd.1bd9af589857b6/bams/test.alignReads /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-09-23 23:39:40.759854 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-09-23 23:39:40.854913 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReadsOneSingleEnd.1bd9af589857b6/results/test.alignReads.summary_alignment.tab
2024-09-23 23:39:40.898996 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.alignReadsOneSingleEnd.1bd9af589857b6/results/test.alignReads.summary_analyzed_bamstats.tab
2024-09-23 23:39:40.900572 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.001 0.001 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= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:39:41.218175 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.genotype.1bd9af4f0f7a71/results/test_pe.coverage.RData
2024-09-23 23:39:41.220135 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp0futa1/test.genotype.1bd9af4f0f7a71/results/test_pe.coverage.bw
2024-09-23 23:39:41.345451 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.genotype.1bd9af4f0f7a71/results/test_pe.summary_coverage.tab
2024-09-23 23:39:41.347109 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-23 23:39:51.922943 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-23 23:39:52.045017 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-23 23:39:52.067952 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-23 23:39:52.069723 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.genotype.1bd9af4f0f7a71/results/test_pe.raw_variants.RData
2024-09-23 23:39:52.072514 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.genotype.1bd9af4f0f7a71/results/test_pe.filtered_variants.RData
2024-09-23 23:39:52.074121 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-23 23:39:52.075551 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-23 23:39:52.568457 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-23 23:39:52.569668 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-09-23 23:40:51.309102 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-23 23:40:51.73654 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-23 23:40:51.737527 INFO::analyzeVariants.R/.callGenotypes: done
[W::bcf_hdr_check_sanity] PL should be declared as Number=G
 done successfully.



Executing test function test.wrap.callVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:40:52.19838 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-23 23:41:02.347787 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-23 23:41:02.422631 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-23 23:41:02.4392 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-23 23:41:02.440523 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.1bd9af522dd074/results/test_pe.raw_variants.RData
2024-09-23 23:41:02.442888 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.1bd9af522dd074/results/test_pe.filtered_variants.RData
2024-09-23 23:41:02.44425 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:41:02.584074 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-23 23:41:12.723415 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-23 23:41:12.780307 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-23 23:41:12.796667 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-23 23:41:12.798129 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.filters.1bd9af35ecd2bc/results/test_pe.raw_variants.RData
2024-09-23 23:41:12.800776 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.filters.1bd9af35ecd2bc/results/test_pe.filtered_variants.RData
2024-09-23 23:41:12.802002 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-23 23:41:12.803491 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-23 23:41:23.030116 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-23 23:41:23.068483 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-23 23:41:23.08524 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-23 23:41:23.086603 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.filters.1bd9af35ecd2bc/results/test_pe.raw_variants.RData
2024-09-23 23:41:23.089181 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.filters.1bd9af35ecd2bc/results/test_pe.filtered_variants.RData
2024-09-23 23:41:23.091148 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:41:23.371588 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-23 23:41:23.37322 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-09-23 23:41:26.279933 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-23 23:41:26.350653 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-23 23:41:26.366255 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-23 23:41:26.367508 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.which.1bd9af22f9201a/results/test_pe.raw_variants.RData
2024-09-23 23:41:26.369056 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.wrap.callVariants.which.1bd9af22f9201a/results/test_pe.filtered_variants.RData
2024-09-23 23:41:26.370247 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:41:27.923958 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-23 23:41:27.925054 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:41:28.070344 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-23 23:41:28.265649 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



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



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



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



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



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



Executing test function test.mergeCoverage  ... 2024-09-23 23:42:18.022748 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/ubvmpeok/merged/results/bla.coverage.RData
2024-09-23 23:42:18.025978 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp0futa1/ubvmpeok/merged/results/bla.coverage.bw
2024-09-23 23:42:18.101838 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/ubvmpeok/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-09-23 23:42:19.18364 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/jzcvkxti/merged/results/bla.coverage.RData
2024-09-23 23:42:19.18503 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp0futa1/jzcvkxti/merged/results/bla.coverage.bw
2024-09-23 23:42:19.19578 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/jzcvkxti/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.findTemplate  ...  done successfully.



Executing test function test.checkConfig  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.getConfig  ...  done successfully.



Executing test function test.loadConfig  ...  done successfully.



Executing test function test.parseDCF  ...  done successfully.



Executing test function test.updateConfig  ...  done successfully.



Executing test function test.getAdapterSeqs  ...  done successfully.



Executing test function test.isAdapter  ...  done successfully.



Executing test function test.isAdapter3.primeEnd  ...  done successfully.



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:21.412449 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-09-23 23:42:21.4135 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp0futa1/test.detectRRNA.1bd9af9b4633f/bams/rRNA_contam/input1.fastq
2024-09-23 23:42:21.416582 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp0futa1/test.detectRRNA.1bd9af9b4633f/bams/rRNA_contam/test_se /tmp/Rtmp0futa1/test.detectRRNA.1bd9af9b4633f/bams/rRNA_contam/input1.fastq 2>&1
2024-09-23 23:42:21.547091 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-09-23 23:42:21.548029 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:21.658467 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-09-23 23:42:21.659411 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp0futa1/test.detectRRNA.paired_end.1bd9af1cf90359/bams/rRNA_contam/input1.fastq
2024-09-23 23:42:21.66079 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp0futa1/test.detectRRNA.paired_end.1bd9af1cf90359/bams/rRNA_contam/input2.fastq
2024-09-23 23:42:21.6628 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp0futa1/test.detectRRNA.paired_end.1bd9af1cf90359/bams/rRNA_contam/test_pe /tmp/Rtmp0futa1/test.detectRRNA.paired_end.1bd9af1cf90359/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp0futa1/test.detectRRNA.paired_end.1bd9af1cf90359/bams/rRNA_contam/input2.fastq 2>&1
2024-09-23 23:42:21.884303 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-09-23 23:42:21.885253 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-09-23 23:42:21.90307 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp0futa1/test_get_rRNA_idslxdbjoui/test_pe /tmp/Rtmp0futa1/test_get_rRNA_idslxdbjoui/1.fastq -a paired /tmp/Rtmp0futa1/test_get_rRNA_idslxdbjoui/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-09-23 23:42:22.141792 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmp0futa1/test_get_rRNAIds_randomgeascouh/test_pe /tmp/Rtmp0futa1/test_get_rRNAIds_randomgeascouh/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-09-23 23:42:22.36526 INFO::filterQuality.R/filterQuality: filterByLength...
2024-09-23 23:42:22.366724 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-09-23 23:42:22.367526 INFO::filterQuality.R/filterByLength: done
2024-09-23 23:42:22.412364 INFO::filterQuality.R/filterQuality: filterByLength...
2024-09-23 23:42:22.413256 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-09-23 23:42:22.414033 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-09-23 23:42:22.461128 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-23 23:42:22.46966 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-09-23 23:42:22.470664 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-23 23:42:22.474832 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-09-23 23:42:22.475749 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-23 23:42:22.479925 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-09-23 23:42:22.480843 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-23 23:42:22.484937 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= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:22.727038 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:22.729147 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.pefq.subsample  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:22.875357 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:22.949732 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-09-23 23:42:22.952646 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:22.954811 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:23.146034 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:23.282542 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:23.430897 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:23.472731 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-09-23 23:42:23.475076 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:23.477181 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:23.647804 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:23.694968 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-09-23 23:42:23.697275 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:23.69933 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.createTmpDir  ...  done successfully.



Executing test function test.detectQualityInFASTQFile  ...  done successfully.



Executing test function test.getObjectFilename  ...  done successfully.



Executing test function test.safeUnlink  ...  done successfully.



Executing test function test.writeAudit  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:42:24.318037 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-23 23:42:24.323578 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:42:24.327041 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-23 23:42:24.329189 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:42:27.181482 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:42:27.182776 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000001/logs/progress.log
2024-09-23 23:42:29.754717 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-09-23 23:42:29.756558 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000002/logs/progress.log
2024-09-23 23:42:32.366398 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-09-23 23:42:32.367861 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000003/logs/progress.log
2024-09-23 23:42:34.97026 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-09-23 23:42:35.033044 DEBUG::tools.R/processChunks: done
2024-09-23 23:42:35.036905 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:42:35.039314 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.adapter_contaminated_1.RData
2024-09-23 23:42:35.042344 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-23 23:42:35.044598 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.adapter_contaminated_2.RData
2024-09-23 23:42:35.055861 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-09-23 23:42:35.05842 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.summary_preprocess.tab
2024-09-23 23:42:35.061764 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/bams/processed.aligner_input_1.fastq ...
2024-09-23 23:42:35.067364 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/bams/processed.aligner_input_2.fastq ...
2024-09-23 23:42:35.071361 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/reports/shortReadReport_1 ...
2024-09-23 23:42:36.391128 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/reports/shortReadReport_2 ...
2024-09-23 23:42:37.437478 INFO::preprocessReads.R/preprocessReads: done
2024-09-23 23:42:37.527563 INFO::alignReads.R/alignReads: starting alignment...
2024-09-23 23:42:37.532237 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:42:40.971974 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:42:40.973622 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000001/logs/progress.log
2024-09-23 23:42:43.54269 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-09-23 23:42:43.544256 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-23 23:42:46.146054 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-09-23 23:42:46.147782 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-23 23:42:48.764116 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-09-23 23:42:48.767208 DEBUG::tools.R/processChunks: done
2024-09-23 23:42:48.769047 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-23 23:42:48.972378 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-09-23 23:42:48.9799 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.summary_alignment.tab
2024-09-23 23:42:48.98649 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.summary_analyzed_bamstats.tab
2024-09-23 23:42:48.98822 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-09-23 23:42:49.21524 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.summary_target_lengths.tab
2024-09-23 23:42:49.261373 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-09-23 23:42:49.262447 INFO::alignReads.R/alignReads: done
2024-09-23 23:42:49.35978 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-09-23 23:42:49.37969 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:42:52.813465 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:42:52.815132 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000001/logs/progress.log
2024-09-23 23:42:55.30072 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2024-09-23 23:42:55.302318 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000002/logs/progress.log
2024-09-23 23:42:57.774101 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2024-09-23 23:42:57.776041 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000003/logs/progress.log
2024-09-23 23:43:00.250233 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2024-09-23 23:43:00.252969 DEBUG::tools.R/processChunks: done
2024-09-23 23:43:00.254809 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-09-23 23:43:00.271043 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.counts_exon.tab
2024-09-23 23:43:00.284054 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.counts_exon_disjoint.tab
2024-09-23 23:43:00.291985 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.counts_gene.tab
2024-09-23 23:43:00.298075 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.counts_gene_coding.tab
2024-09-23 23:43:00.303757 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.counts_gene_exonic.tab
2024-09-23 23:43:00.309035 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.counts_intergenic.tab
2024-09-23 23:43:00.317982 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.counts_intron.tab
2024-09-23 23:43:00.320435 INFO::countGenomicFeatures.R/mergeCounts: done
2024-09-23 23:43:00.325575 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.summary_counts.tab
2024-09-23 23:43:00.32701 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-09-23 23:43:00.62996 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-09-23 23:43:00.630811 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-09-23 23:43:00.739864 INFO::coverage.R/calculateCoverage: starting...
2024-09-23 23:43:00.744326 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:43:03.611608 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:43:03.613192 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000001/logs/progress.log
2024-09-23 23:43:05.788606 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-09-23 23:43:05.79019 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000002/logs/progress.log
2024-09-23 23:43:07.970968 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-09-23 23:43:07.972558 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/chunks/chunk_000003/logs/progress.log
2024-09-23 23:43:10.182903 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2024-09-23 23:43:10.18753 DEBUG::tools.R/processChunks: done
2024-09-23 23:43:12.510285 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.coverage.RData
2024-09-23 23:43:12.512223 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.coverage.bw
2024-09-23 23:43:12.527775 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.summary_coverage.tab
2024-09-23 23:43:12.529128 INFO::coverage.R/calculateCoverage: done
2024-09-23 23:43:12.53114 INFO::analyzeVariants/analyzeVariants: starting ...
2024-09-23 23:43:12.625084 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-23 23:43:15.719078 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-23 23:43:15.788553 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-23 23:43:15.804364 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-23 23:43:15.805642 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.raw_variants.RData
2024-09-23 23:43:15.807225 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.filtered_variants.RData
2024-09-23 23:43:15.808487 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-23 23:43:15.809427 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-23 23:43:16.012719 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-23 23:43:16.108417 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/results/test_pe.summary_variants.tab
2024-09-23 23:43:16.110515 INFO::analyzeVariants/analyzeVariants: done
2024-09-23 23:43:16.114947 INFO::Pipeline run successful.
2024-09-23 23:43:16.285442 INFO::mergeLanes.R/doMergeLanes: starting...
2024-09-23 23:43:16.290097 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:43:16.292258 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.adapter_contaminated_1.RData
2024-09-23 23:43:16.295085 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-23 23:43:16.297024 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.adapter_contaminated_2.RData
2024-09-23 23:43:16.308271 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-09-23 23:43:16.310467 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.summary_preprocess.tab
2024-09-23 23:43:16.312564 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-23 23:43:16.554412 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-09-23 23:43:16.562177 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.summary_alignment.tab
2024-09-23 23:43:16.570549 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.summary_analyzed_bamstats.tab
2024-09-23 23:43:16.57279 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-09-23 23:43:16.820179 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.summary_target_lengths.tab
2024-09-23 23:43:16.870483 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-09-23 23:43:16.915314 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-09-23 23:43:16.936652 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.counts_exon.tab
2024-09-23 23:43:16.949242 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.counts_exon_disjoint.tab
2024-09-23 23:43:16.95634 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.counts_gene.tab
2024-09-23 23:43:16.962148 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.counts_gene_coding.tab
2024-09-23 23:43:16.968133 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.counts_gene_exonic.tab
2024-09-23 23:43:16.974105 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.counts_intergenic.tab
2024-09-23 23:43:16.986268 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.counts_intron.tab
2024-09-23 23:43:16.98903 INFO::countGenomicFeatures.R/mergeCounts: done
2024-09-23 23:43:16.995987 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.summary_counts.tab
2024-09-23 23:43:16.997856 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-09-23 23:43:17.239052 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-09-23 23:43:19.233685 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.coverage.RData
2024-09-23 23:43:19.236711 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.coverage.bw
2024-09-23 23:43:19.248698 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.summary_coverage.tab
2024-09-23 23:43:19.297129 INFO::analyzeVariants/analyzeVariants: starting ...
2024-09-23 23:43:19.379286 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-23 23:43:22.300334 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-23 23:43:22.374713 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-23 23:43:22.391584 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-23 23:43:22.393011 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.raw_variants.RData
2024-09-23 23:43:22.394675 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.filtered_variants.RData
2024-09-23 23:43:22.395936 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-23 23:43:22.396906 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-23 23:43:22.616709 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-23 23:43:22.720896 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.mergeLanes.1bd9af46c09fbb/merged/results/merged.summary_variants.tab
2024-09-23 23:43:22.723216 INFO::analyzeVariants/analyzeVariants: done
2024-09-23 23:43:22.726735 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= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:43:23.020902 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-23 23:43:23.027827 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:43:23.031869 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-23 23:43:23.034748 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:43:26.379107 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:43:26.380637 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/chunks/chunk_000001/logs/progress.log
2024-09-23 23:43:28.998593 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-09-23 23:43:29.074385 DEBUG::tools.R/processChunks: done
2024-09-23 23:43:29.078127 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:43:29.080692 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/results/test_pe.adapter_contaminated_1.RData
2024-09-23 23:43:29.083517 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-23 23:43:29.085703 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/results/test_pe.adapter_contaminated_2.RData
2024-09-23 23:43:29.095595 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-09-23 23:43:29.098518 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/results/test_pe.summary_preprocess.tab
2024-09-23 23:43:29.101824 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/bams/processed.aligner_input_1.fastq ...
2024-09-23 23:43:29.107537 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/bams/processed.aligner_input_2.fastq ...
2024-09-23 23:43:29.112861 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/reports/shortReadReport_1 ...
2024-09-23 23:43:30.528095 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.preprocessReads.1bd9af2523a78c/reports/shortReadReport_2 ...
2024-09-23 23:43:31.65307 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:43:31.9382 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-23 23:43:31.944079 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:43:31.947401 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-23 23:43:31.949712 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:43:35.15241 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:43:35.153834 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/chunks/chunk_000001/logs/progress.log
2024-09-23 23:43:37.78951 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-09-23 23:43:37.790848 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/chunks/chunk_000002/logs/progress.log
2024-09-23 23:43:40.376978 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-09-23 23:43:40.37856 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/chunks/chunk_000003/logs/progress.log
2024-09-23 23:43:43.286041 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2024-09-23 23:43:43.338244 DEBUG::tools.R/processChunks: done
2024-09-23 23:43:43.341399 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:43:43.343248 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/results/test_pe.adapter_contaminated_1.RData
2024-09-23 23:43:43.345601 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-23 23:43:43.347174 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/results/test_pe.adapter_contaminated_2.RData
2024-09-23 23:43:43.356294 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-09-23 23:43:43.358265 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/results/test_pe.summary_preprocess.tab
2024-09-23 23:43:43.360918 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/bams/processed.aligner_input_1.fastq ...
2024-09-23 23:43:43.365433 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/bams/processed.aligner_input_2.fastq ...
2024-09-23 23:43:43.36868 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/reports/shortReadReport_1 ...
2024-09-23 23:43:44.82923 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.preprocessReads.minichunks.1bd9af3dbb8e7/reports/shortReadReport_2 ...
2024-09-23 23:43:47.266016 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp0futa1/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:43:48.010309 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-23 23:43:48.029079 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-23 23:43:48.042368 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:43:54.489384 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:43:54.492115 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp0futa1/test.preprocessReads_single_end.1bd9af7c7de0d7/chunks/chunk_000001/logs/progress.log
2024-09-23 23:43:57.481028 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2024-09-23 23:43:57.652839 DEBUG::tools.R/processChunks: done
2024-09-23 23:43:57.664299 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:43:57.667398 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads_single_end.1bd9af7c7de0d7/results/test_se.adapter_contaminated_1.RData
2024-09-23 23:43:57.695269 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-09-23 23:43:57.706059 INFO::io.R/saveWithID: saving file= /tmp/Rtmp0futa1/test.preprocessReads_single_end.1bd9af7c7de0d7/results/test_se.summary_preprocess.tab
2024-09-23 23:43:57.710003 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp0futa1/test.preprocessReads_single_end.1bd9af7c7de0d7/bams/processed.aligner_input_1.fastq ...
2024-09-23 23:43:57.724099 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp0futa1/test.preprocessReads_single_end.1bd9af7c7de0d7/reports/shortReadReport_1 ...
2024-09-23 23:44:02.321105 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.readRNASeqEnds  ...  done successfully.



Executing test function test.readRNASeqEnds.dupmark  ...  done successfully.



Executing test function test.how_many  ...  done successfully.



Executing test function test.plotDF  ...  done successfully.



Executing test function test.relativeBarPlot  ...  done successfully.



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-23 23:44:04.563066 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-23 23:44:04.584879 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-09-23 23:44:04.602938 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-09-23 23:44:04.61236 DEBUG::tools.R/processChunks: starting...
2024-09-23 23:44:09.253139 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-23 23:44:09.254642 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-09-23 23:44:13.052906 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.063 minutes
2024-09-23 23:44:13.182396 DEBUG::tools.R/processChunks: done
2024-09-23 23:44:13.18836 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-23 23:44:13.191817 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-09-23 23:44:13.195756 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-23 23:44:13.198887 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-09-23 23:44:13.215723 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2500 highqual_reads=2500 adapter_contam=0 read_length=100 rRNA_contam_reads=0 processed_reads=2500 input_min_read_length=100 input_max_read_length=100 processed_min_read_length=71 processed_max_read_length=100
2024-09-23 23:44:13.22057 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-09-23 23:44:13.226182 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-09-23 23:44:13.237349 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-09-23 23:44:13.24825 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-09-23 23:45:04.45156 DEBUG::tools.R/traceMem: wired.mem=-63.542612 GiB
2024-09-23 23:46:04.517763 DEBUG::tools.R/traceMem: wired.mem=-67.986944 GiB
2024-09-23 23:47:04.582203 DEBUG::tools.R/traceMem: wired.mem=-68.390212 GiB
2024-09-23 23:48:04.647827 DEBUG::tools.R/traceMem: wired.mem=-65.257107 GiB
2024-09-23 23:49:04.713104 DEBUG::tools.R/traceMem: wired.mem=-61.684330 GiB
2024-09-23 23:50:04.77715 DEBUG::tools.R/traceMem: wired.mem=-62.617981 GiB
2024-09-23 23:51:04.841969 DEBUG::tools.R/traceMem: wired.mem=-68.052570 GiB
2024-09-23 23:52:04.908874 DEBUG::tools.R/traceMem: wired.mem=-52.003500 GiB
2024-09-23 23:53:04.976613 DEBUG::tools.R/traceMem: wired.mem=-58.807742 GiB
2024-09-23 23:54:05.044437 DEBUG::tools.R/traceMem: wired.mem=-54.516797 GiB
2024-09-23 23:55:05.111207 DEBUG::tools.R/traceMem: wired.mem=-67.105378 GiB
2024-09-23 23:56:05.175506 DEBUG::tools.R/traceMem: wired.mem=-61.577966 GiB
2024-09-23 23:57:05.24035 DEBUG::tools.R/traceMem: wired.mem=-68.172468 GiB
2024-09-23 23:58:05.30565 DEBUG::tools.R/traceMem: wired.mem=-68.396323 GiB
2024-09-23 23:59:05.372674 DEBUG::tools.R/traceMem: wired.mem=-68.628427 GiB
2024-09-24 00:00:05.437694 DEBUG::tools.R/traceMem: wired.mem=-68.448662 GiB
2024-09-24 00:01:05.502946 DEBUG::tools.R/traceMem: wired.mem=-79.022313 GiB
2024-09-24 00:02:05.567014 DEBUG::tools.R/traceMem: wired.mem=-72.957358 GiB
2024-09-24 00:03:05.631845 DEBUG::tools.R/traceMem: wired.mem=-67.364377 GiB
2024-09-24 00:04:05.698471 DEBUG::tools.R/traceMem: wired.mem=-73.932165 GiB
2024-09-24 00:05:05.763718 DEBUG::tools.R/traceMem: wired.mem=-71.077499 GiB
2024-09-24 00:06:05.830787 DEBUG::tools.R/traceMem: wired.mem=-69.269705 GiB
2024-09-24 00:07:05.895607 DEBUG::tools.R/traceMem: wired.mem=-71.957434 GiB
2024-09-24 00:08:05.962803 DEBUG::tools.R/traceMem: wired.mem=-65.158345 GiB
2024-09-24 00:09:06.028721 DEBUG::tools.R/traceMem: wired.mem=-65.760186 GiB
2024-09-24 00:10:06.095591 DEBUG::tools.R/traceMem: wired.mem=-55.436636 GiB
2024-09-24 00:11:06.160802 DEBUG::tools.R/traceMem: wired.mem=-63.305716 GiB
2024-09-24 00:12:06.227494 DEBUG::tools.R/traceMem: wired.mem=-61.192196 GiB
2024-09-24 00:13:06.29264 DEBUG::tools.R/traceMem: wired.mem=-63.242334 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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