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

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo2	Linux (Ubuntu 24.04.1 LTS)	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4744
palomino8	Windows Server 2022 Datacenter	x64	4.4.2 (2024-10-31 ucrt) -- "Pile of Leaves"	4487
merida1	macOS 12.7.5 Monterey	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4515
kjohnson1	macOS 13.6.6 Ventura	arm64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4467
Click on any hostname to see more info about the system (e.g. compilers) () as reported by 'uname -p', except on Windows and Mac OS X*

CHECK results for HTSeqGenie on nebbiolo2

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

raw results

Summary

Package: HTSeqGenie

Version: 4.36.0

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

StartedAt: 2024-12-30 22:54:37 -0500 (Mon, 30 Dec 2024)

EndedAt: 2024-12-30 23:34:37 -0500 (Mon, 30 Dec 2024)

EllapsedTime: 2400.8 seconds

RetCode: None

Status: TIMEOUT

CheckDir: HTSeqGenie.Rcheck

Warnings: NA

Command output

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


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

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

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

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

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

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

Installation output

HTSeqGenie.Rcheck/00install.out

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


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

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


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

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

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

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

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

Attaching package: 'BiocGenerics'

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

    IQR, mad, sd, var, xtabs

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

    Filter, Find, Map, Position, Reduce, anyDuplicated, aperm, append,
    as.data.frame, basename, cbind, colnames, dirname, do.call,
    duplicated, eval, evalq, get, grep, grepl, intersect, is.unsorted,
    lapply, mapply, match, mget, order, paste, pmax, pmax.int, pmin,
    pmin.int, rank, rbind, rownames, sapply, saveRDS, setdiff, table,
    tapply, union, unique, unsplit, which.max, which.min

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

The following object is masked from 'package:utils':

    findMatches

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

    I, expand.grid, unname

Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector

Attaching package: 'Biostrings'

The following object is masked from 'package:base':

    strsplit

Loading required package: ShortRead
Loading required package: BiocParallel
Loading required package: GenomicAlignments
Loading required package: SummarizedExperiment
Loading required package: MatrixGenerics
Loading required package: matrixStats

Attaching package: 'MatrixGenerics'

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

    colAlls, colAnyNAs, colAnys, colAvgsPerRowSet, colCollapse,
    colCounts, colCummaxs, colCummins, colCumprods, colCumsums,
    colDiffs, colIQRDiffs, colIQRs, colLogSumExps, colMadDiffs,
    colMads, colMaxs, colMeans2, colMedians, colMins, colOrderStats,
    colProds, colQuantiles, colRanges, colRanks, colSdDiffs, colSds,
    colSums2, colTabulates, colVarDiffs, colVars, colWeightedMads,
    colWeightedMeans, colWeightedMedians, colWeightedSds,
    colWeightedVars, rowAlls, rowAnyNAs, rowAnys, rowAvgsPerColSet,
    rowCollapse, rowCounts, rowCummaxs, rowCummins, rowCumprods,
    rowCumsums, rowDiffs, rowIQRDiffs, rowIQRs, rowLogSumExps,
    rowMadDiffs, rowMads, rowMaxs, rowMeans2, rowMedians, rowMins,
    rowOrderStats, rowProds, rowQuantiles, rowRanges, rowRanks,
    rowSdDiffs, rowSds, rowSums2, rowTabulates, rowVarDiffs, rowVars,
    rowWeightedMads, rowWeightedMeans, rowWeightedMedians,
    rowWeightedSds, rowWeightedVars

Loading required package: Biobase
Welcome to Bioconductor

    Vignettes contain introductory material; view with
    'browseVignettes()'. To cite Bioconductor, see
    'citation("Biobase")', and for packages 'citation("pkgname")'.


Attaching package: 'Biobase'

The following object is masked from 'package:MatrixGenerics':

    rowMedians

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

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

The following object is masked from 'package:base':

    tabulate

> 
> source(getPackageFile("unitTests/runTests.R"))
Loading required package: GenomicFeatures
Loading required package: AnnotationDbi
did not source anything in dirname= ./R 


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:00:14.206825 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-30 23:00:14.214835 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:00:14.218294 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-12-30 23:00:14.220393 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:00:17.157116 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:00:17.158447 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/chunks/chunk_000001/logs/progress.log
2024-12-30 23:00:19.946968 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-12-30 23:00:19.948711 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/chunks/chunk_000002/logs/progress.log
2024-12-30 23:00:22.699002 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-12-30 23:00:22.700366 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/chunks/chunk_000003/logs/progress.log
2024-12-30 23:00:25.450975 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-12-30 23:00:25.483593 DEBUG::tools.R/processChunks: done
2024-12-30 23:00:25.487448 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:00:25.4896 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/results/test_pe.adapter_contaminated_1.RData
2024-12-30 23:00:25.492188 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-30 23:00:25.49373 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/results/test_pe.adapter_contaminated_2.RData
2024-12-30 23:00:25.502715 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-12-30 23:00:25.504832 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/results/test_pe.summary_preprocess.tab
2024-12-30 23:00:25.507955 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/bams/processed.aligner_input_1.fastq ...
2024-12-30 23:00:25.512101 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/bams/processed.aligner_input_2.fastq ...
2024-12-30 23:00:25.515036 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/reports/shortReadReport_1 ...
2024-12-30 23:00:26.925789 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/reports/shortReadReport_2 ...
2024-12-30 23:00:28.112006 INFO::preprocessReads.R/preprocessReads: done
2024-12-30 23:00:28.211993 INFO::alignReads.R/alignReads: starting alignment...
2024-12-30 23:00:28.217535 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:00:31.198683 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:00:31.200261 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/chunks/chunk_000001/logs/progress.log
2024-12-30 23:00:34.076784 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2024-12-30 23:00:34.078736 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-12-30 23:00:36.748844 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-12-30 23:00:36.750413 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-12-30 23:00:39.383042 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-12-30 23:00:39.386408 DEBUG::tools.R/processChunks: done
2024-12-30 23:00:39.388258 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-12-30 23:00:39.646182 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-12-30 23:00:39.655034 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/results/test_pe.summary_alignment.tab
2024-12-30 23:00:39.662357 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/results/test_pe.summary_analyzed_bamstats.tab
2024-12-30 23:00:39.664082 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-12-30 23:00:39.901138 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.358f3b49ff09c0/results/test_pe.summary_target_lengths.tab
2024-12-30 23:00:39.947239 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-12-30 23:00:39.948235 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:00:40.217699 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-30 23:00:40.220784 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:00:40.282143 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-12-30 23:00:40.286856 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:00:40.289903 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-12-30 23:00:40.291819 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:00:43.116648 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:00:43.118071 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/chunks/chunk_000001/logs/progress.log
2024-12-30 23:00:45.798641 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-12-30 23:00:45.800194 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/chunks/chunk_000002/logs/progress.log
2024-12-30 23:00:48.521595 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-12-30 23:00:48.52312 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/chunks/chunk_000003/logs/progress.log
2024-12-30 23:00:51.291023 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-12-30 23:00:51.292955 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/chunks/chunk_000004/logs/progress.log
2024-12-30 23:00:53.961504 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2024-12-30 23:00:53.988126 DEBUG::tools.R/processChunks: done
2024-12-30 23:00:53.99113 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:00:53.99319 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/results/test_pe.adapter_contaminated_1.RData
2024-12-30 23:00:53.995855 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-30 23:00:53.997445 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/results/test_pe.adapter_contaminated_2.RData
2024-12-30 23:00:54.006581 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2 highqual_reads=1 adapter_contam=0 read_length=75 rRNA_contam_reads=0 processed_reads=1 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-12-30 23:00:54.008605 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/results/test_pe.summary_preprocess.tab
2024-12-30 23:00:54.011804 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/bams/processed.aligner_input_1.fastq ...
2024-12-30 23:00:54.016521 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/bams/processed.aligner_input_2.fastq ...
2024-12-30 23:00:54.019382 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/reports/shortReadReport_1 ...
2024-12-30 23:00:55.301345 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReads.sparsechunks.358f3b4bb4ff85/reports/shortReadReport_2 ...
2024-12-30 23:00:56.429157 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:00:56.575125 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-12-30 23:00:56.579345 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -D /home/biocbuild/.local/share/gmap -t 1 -d TP53_demo_3.2.2 --quality-protocol=illumina  -A sam --read-group-id=test_se -m 0 --split-output /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReadsOneSingleEnd.358f3b139b4348/bams/test.alignReads /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-12-30 23:00:56.77494 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-12-30 23:00:56.864971 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReadsOneSingleEnd.358f3b139b4348/results/test.alignReads.summary_alignment.tab
2024-12-30 23:00:56.92061 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.alignReadsOneSingleEnd.358f3b139b4348/results/test.alignReads.summary_analyzed_bamstats.tab
2024-12-30 23:00:56.92243 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:00:57.210084 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.genotype.358f3b6b9cd8db/results/test_pe.coverage.RData
2024-12-30 23:00:57.212115 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.genotype.358f3b6b9cd8db/results/test_pe.coverage.bw
2024-12-30 23:00:57.324086 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.genotype.358f3b6b9cd8db/results/test_pe.summary_coverage.tab
2024-12-30 23:00:57.325716 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-30 23:01:07.820736 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-30 23:01:07.911339 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-30 23:01:07.929986 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-30 23:01:07.931706 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.genotype.358f3b6b9cd8db/results/test_pe.raw_variants.RData
2024-12-30 23:01:07.934278 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.genotype.358f3b6b9cd8db/results/test_pe.filtered_variants.RData
2024-12-30 23:01:07.937739 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-30 23:01:07.939055 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-30 23:01:08.396634 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-30 23:01:08.397793 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-12-30 23:02:10.671507 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-30 23:02:11.09119 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-30 23:02:11.092223 INFO::analyzeVariants.R/.callGenotypes: done
[W::bcf_hdr_check_sanity] PL should be declared as Number=G
 done successfully.



Executing test function test.wrap.callVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:02:11.501194 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-30 23:02:21.902735 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-30 23:02:21.980675 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-30 23:02:21.997448 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-30 23:02:21.998784 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.358f3b16676192/results/test_pe.raw_variants.RData
2024-12-30 23:02:22.001143 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.358f3b16676192/results/test_pe.filtered_variants.RData
2024-12-30 23:02:22.002511 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:02:22.144023 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-30 23:02:32.221479 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-30 23:02:32.279689 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-30 23:02:32.296726 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-30 23:02:32.298106 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.filters.358f3bcf817a5/results/test_pe.raw_variants.RData
2024-12-30 23:02:32.300587 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.filters.358f3bcf817a5/results/test_pe.filtered_variants.RData
2024-12-30 23:02:32.30184 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-30 23:02:32.303226 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-30 23:02:42.47417 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-30 23:02:42.513305 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-30 23:02:42.530178 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-30 23:02:42.53157 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.filters.358f3bcf817a5/results/test_pe.raw_variants.RData
2024-12-30 23:02:42.5341 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.filters.358f3bcf817a5/results/test_pe.filtered_variants.RData
2024-12-30 23:02:42.536106 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:02:42.777336 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-30 23:02:42.77898 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-12-30 23:02:45.555539 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-30 23:02:45.641967 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-30 23:02:45.660439 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-30 23:02:45.662026 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.which.358f3b21b7edcd/results/test_pe.raw_variants.RData
2024-12-30 23:02:45.663885 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.wrap.callVariants.which.358f3b21b7edcd/results/test_pe.filtered_variants.RData
2024-12-30 23:02:45.665269 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:02:45.876593 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-30 23:02:45.878179 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:02:48.250729 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-30 23:02:48.441146 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



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



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



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



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



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



Executing test function test.mergeCoverage  ... 2024-12-30 23:03:38.744511 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/lkpiovwe/merged/results/bla.coverage.RData
2024-12-30 23:03:38.747473 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/lkpiovwe/merged/results/bla.coverage.bw
2024-12-30 23:03:38.832737 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/lkpiovwe/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-12-30 23:03:40.184688 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/todhynrw/merged/results/bla.coverage.RData
2024-12-30 23:03:40.187133 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/todhynrw/merged/results/bla.coverage.bw
2024-12-30 23:03:40.198543 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/todhynrw/merged/results/bla.summary_coverage.tab
 done successfully.



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



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



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



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



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



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



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



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



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



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



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



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:41.387437 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-12-30 23:03:41.388508 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.358f3b2fdc49bd/bams/rRNA_contam/input1.fastq
2024-12-30 23:03:41.39179 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.358f3b2fdc49bd/bams/rRNA_contam/test_se /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.358f3b2fdc49bd/bams/rRNA_contam/input1.fastq 2>&1
2024-12-30 23:03:41.534437 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-12-30 23:03:41.535457 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:41.657123 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-12-30 23:03:41.658113 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.paired_end.358f3b3f648641/bams/rRNA_contam/input1.fastq
2024-12-30 23:03:41.659576 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.paired_end.358f3b3f648641/bams/rRNA_contam/input2.fastq
2024-12-30 23:03:41.661657 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.paired_end.358f3b3f648641/bams/rRNA_contam/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.paired_end.358f3b3f648641/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.detectRRNA.paired_end.358f3b3f648641/bams/rRNA_contam/input2.fastq 2>&1
2024-12-30 23:03:41.949153 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-12-30 23:03:41.950163 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-12-30 23:03:41.969209 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test_get_rRNA_idsjaseqmzy/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test_get_rRNA_idsjaseqmzy/1.fastq -a paired /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test_get_rRNA_idsjaseqmzy/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-12-30 23:03:42.225905 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test_get_rRNAIds_randomrgoedxwk/test_pe /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test_get_rRNAIds_randomrgoedxwk/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-12-30 23:03:42.476918 INFO::filterQuality.R/filterQuality: filterByLength...
2024-12-30 23:03:42.478402 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-12-30 23:03:42.479267 INFO::filterQuality.R/filterByLength: done
2024-12-30 23:03:42.525737 INFO::filterQuality.R/filterQuality: filterByLength...
2024-12-30 23:03:42.526779 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-12-30 23:03:42.527617 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-12-30 23:03:42.576502 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-30 23:03:42.585424 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-12-30 23:03:42.58645 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-30 23:03:42.590676 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-12-30 23:03:42.591627 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-30 23:03:42.595756 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-12-30 23:03:42.596666 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-12-30 23:03:42.600885 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:42.861339 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:42.863657 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.pefq.subsample  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:43.006198 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:43.077513 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-12-30 23:03:43.080037 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:43.082083 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:43.271276 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:43.413939 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:43.575413 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:43.619997 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-12-30 23:03:43.622353 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:43.624472 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:43.797373 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:43.841624 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-12-30 23:03:43.844032 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:43.846334 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



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



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



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:03:44.522696 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-30 23:03:44.529117 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:03:44.532817 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-12-30 23:03:44.535393 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:03:47.693652 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:03:47.695135 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000001/logs/progress.log
2024-12-30 23:03:50.32672 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-12-30 23:03:50.328276 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000002/logs/progress.log
2024-12-30 23:03:52.928198 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-12-30 23:03:52.929632 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000003/logs/progress.log
2024-12-30 23:03:55.597057 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-12-30 23:03:55.651435 DEBUG::tools.R/processChunks: done
2024-12-30 23:03:55.654224 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:03:55.655829 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.adapter_contaminated_1.RData
2024-12-30 23:03:55.657854 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-30 23:03:55.659308 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.adapter_contaminated_2.RData
2024-12-30 23:03:55.666804 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-12-30 23:03:55.66848 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.summary_preprocess.tab
2024-12-30 23:03:55.670758 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/bams/processed.aligner_input_1.fastq ...
2024-12-30 23:03:55.674614 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/bams/processed.aligner_input_2.fastq ...
2024-12-30 23:03:55.67769 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/reports/shortReadReport_1 ...
2024-12-30 23:03:56.986158 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/reports/shortReadReport_2 ...
2024-12-30 23:03:58.110119 INFO::preprocessReads.R/preprocessReads: done
2024-12-30 23:03:58.247351 INFO::alignReads.R/alignReads: starting alignment...
2024-12-30 23:03:58.251979 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:04:01.38032 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:04:01.382026 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000001/logs/progress.log
2024-12-30 23:04:03.962227 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-12-30 23:04:03.963734 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-12-30 23:04:06.572549 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-12-30 23:04:06.574377 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000003/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-12-30 23:04:09.173598 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-12-30 23:04:09.175751 DEBUG::tools.R/processChunks: done
2024-12-30 23:04:09.177082 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-12-30 23:04:09.358908 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-12-30 23:04:09.366379 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.summary_alignment.tab
2024-12-30 23:04:09.372954 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.summary_analyzed_bamstats.tab
2024-12-30 23:04:09.374846 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-12-30 23:04:09.587247 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.summary_target_lengths.tab
2024-12-30 23:04:09.632323 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-12-30 23:04:09.633279 INFO::alignReads.R/alignReads: done
2024-12-30 23:04:09.731982 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-12-30 23:04:09.749914 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:04:12.916378 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:04:12.917905 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000001/logs/progress.log
2024-12-30 23:04:15.651875 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-12-30 23:04:15.653733 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000002/logs/progress.log
2024-12-30 23:04:19.183369 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.059 minutes
2024-12-30 23:04:19.191069 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000003/logs/progress.log
2024-12-30 23:04:22.497762 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.055 minutes
2024-12-30 23:04:22.506681 DEBUG::tools.R/processChunks: done
2024-12-30 23:04:22.513319 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-12-30 23:04:22.574013 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.counts_exon.tab
2024-12-30 23:04:22.623861 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.counts_exon_disjoint.tab
2024-12-30 23:04:22.66254 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.counts_gene.tab
2024-12-30 23:04:22.707768 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.counts_gene_coding.tab
2024-12-30 23:04:22.742381 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.counts_gene_exonic.tab
2024-12-30 23:04:22.767064 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.counts_intergenic.tab
2024-12-30 23:04:22.804604 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.counts_intron.tab
2024-12-30 23:04:22.818884 INFO::countGenomicFeatures.R/mergeCounts: done
2024-12-30 23:04:22.839456 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.summary_counts.tab
2024-12-30 23:04:22.845684 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-12-30 23:04:23.713087 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-12-30 23:04:23.719392 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-12-30 23:04:24.057804 INFO::coverage.R/calculateCoverage: starting...
2024-12-30 23:04:24.076835 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:04:32.372157 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:04:32.375506 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000001/logs/progress.log
2024-12-30 23:04:35.183023 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-12-30 23:04:35.195183 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000002/logs/progress.log
2024-12-30 23:04:37.625443 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2024-12-30 23:04:37.628076 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/chunks/chunk_000003/logs/progress.log
2024-12-30 23:04:39.998419 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.039 minutes
2024-12-30 23:04:40.003182 DEBUG::tools.R/processChunks: done
2024-12-30 23:04:42.154691 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.coverage.RData
2024-12-30 23:04:42.156348 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.coverage.bw
2024-12-30 23:04:42.168998 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.summary_coverage.tab
2024-12-30 23:04:42.17047 INFO::coverage.R/calculateCoverage: done
2024-12-30 23:04:42.172776 INFO::analyzeVariants/analyzeVariants: starting ...
2024-12-30 23:04:42.320078 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-30 23:04:48.639922 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-30 23:04:48.825192 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-30 23:04:48.870214 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-30 23:04:48.873899 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.raw_variants.RData
2024-12-30 23:04:48.87763 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.filtered_variants.RData
2024-12-30 23:04:48.881019 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-30 23:04:48.883626 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-30 23:04:49.512071 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-30 23:04:49.761017 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/results/test_pe.summary_variants.tab
2024-12-30 23:04:49.765629 INFO::analyzeVariants/analyzeVariants: done
2024-12-30 23:04:49.772648 INFO::Pipeline run successful.
2024-12-30 23:04:50.178123 INFO::mergeLanes.R/doMergeLanes: starting...
2024-12-30 23:04:50.187998 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:04:50.192481 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.adapter_contaminated_1.RData
2024-12-30 23:04:50.198796 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-30 23:04:50.203079 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.adapter_contaminated_2.RData
2024-12-30 23:04:50.230562 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-12-30 23:04:50.235713 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.summary_preprocess.tab
2024-12-30 23:04:50.241278 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-12-30 23:04:50.764459 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-12-30 23:04:50.778789 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.summary_alignment.tab
2024-12-30 23:04:50.795004 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.summary_analyzed_bamstats.tab
2024-12-30 23:04:50.799089 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-12-30 23:04:51.224249 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.summary_target_lengths.tab
2024-12-30 23:04:51.309196 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-12-30 23:04:51.43084 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-12-30 23:04:51.471689 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.counts_exon.tab
2024-12-30 23:04:51.496828 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.counts_exon_disjoint.tab
2024-12-30 23:04:51.512726 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.counts_gene.tab
2024-12-30 23:04:51.525476 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.counts_gene_coding.tab
2024-12-30 23:04:51.537628 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.counts_gene_exonic.tab
2024-12-30 23:04:51.550762 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.counts_intergenic.tab
2024-12-30 23:04:51.57692 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.counts_intron.tab
2024-12-30 23:04:51.583137 INFO::countGenomicFeatures.R/mergeCounts: done
2024-12-30 23:04:51.596344 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.summary_counts.tab
2024-12-30 23:04:51.600244 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-12-30 23:04:51.984352 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-12-30 23:04:56.373921 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.coverage.RData
2024-12-30 23:04:56.381143 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.coverage.bw
2024-12-30 23:04:56.414141 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.summary_coverage.tab
2024-12-30 23:04:56.56066 INFO::analyzeVariants/analyzeVariants: starting ...
2024-12-30 23:04:56.816169 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-12-30 23:05:02.809668 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-12-30 23:05:02.919357 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-12-30 23:05:02.94356 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-12-30 23:05:02.945627 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.raw_variants.RData
2024-12-30 23:05:02.947923 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.filtered_variants.RData
2024-12-30 23:05:02.949713 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-12-30 23:05:02.950959 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-12-30 23:05:03.258904 INFO::analyzeVariants.R/writeVCF: ...done
2024-12-30 23:05:03.391235 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.mergeLanes.358f3b16391722/merged/results/merged.summary_variants.tab
2024-12-30 23:05:03.394844 INFO::analyzeVariants/analyzeVariants: done
2024-12-30 23:05:03.400388 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:05:03.883958 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-30 23:05:03.893188 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:05:03.898387 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-12-30 23:05:03.902324 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:05:07.923624 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:05:07.925174 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/chunks/chunk_000001/logs/progress.log
2024-12-30 23:05:10.540448 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-12-30 23:05:10.61109 DEBUG::tools.R/processChunks: done
2024-12-30 23:05:10.614522 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:05:10.616793 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/results/test_pe.adapter_contaminated_1.RData
2024-12-30 23:05:10.61928 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-30 23:05:10.621343 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/results/test_pe.adapter_contaminated_2.RData
2024-12-30 23:05:10.630519 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-12-30 23:05:10.633102 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/results/test_pe.summary_preprocess.tab
2024-12-30 23:05:10.636075 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/bams/processed.aligner_input_1.fastq ...
2024-12-30 23:05:10.641446 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/bams/processed.aligner_input_2.fastq ...
2024-12-30 23:05:10.64622 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/reports/shortReadReport_1 ...
2024-12-30 23:05:12.045619 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.358f3b6ab393c6/reports/shortReadReport_2 ...
2024-12-30 23:05:13.206144 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:05:13.481548 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-30 23:05:13.487097 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:05:13.490535 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-12-30 23:05:13.492691 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:05:17.341515 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:05:17.342961 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/chunks/chunk_000001/logs/progress.log
2024-12-30 23:05:19.934558 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-12-30 23:05:19.936645 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/chunks/chunk_000002/logs/progress.log
2024-12-30 23:05:22.507776 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-12-30 23:05:22.509293 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/chunks/chunk_000003/logs/progress.log
2024-12-30 23:05:25.137535 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-12-30 23:05:25.1878 DEBUG::tools.R/processChunks: done
2024-12-30 23:05:25.190753 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:05:25.192453 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/results/test_pe.adapter_contaminated_1.RData
2024-12-30 23:05:25.194561 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-30 23:05:25.196037 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/results/test_pe.adapter_contaminated_2.RData
2024-12-30 23:05:25.204462 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-12-30 23:05:25.206316 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/results/test_pe.summary_preprocess.tab
2024-12-30 23:05:25.208767 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/bams/processed.aligner_input_1.fastq ...
2024-12-30 23:05:25.212667 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/bams/processed.aligner_input_2.fastq ...
2024-12-30 23:05:25.21625 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/reports/shortReadReport_1 ...
2024-12-30 23:05:26.55396 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads.minichunks.358f3b7a36f90/reports/shortReadReport_2 ...
2024-12-30 23:05:27.666686 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:05:27.978203 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-30 23:05:27.999143 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-12-30 23:05:28.001838 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:05:31.033312 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:05:31.034655 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads_single_end.358f3b4f1e70da/chunks/chunk_000001/logs/progress.log
2024-12-30 23:05:33.40041 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-12-30 23:05:33.438693 DEBUG::tools.R/processChunks: done
2024-12-30 23:05:33.441256 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:05:33.442828 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads_single_end.358f3b4f1e70da/results/test_se.adapter_contaminated_1.RData
2024-12-30 23:05:33.448916 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=26 highqual_reads=25 adapter_contam=1 read_length=75 rRNA_contam_reads=0 processed_reads=25 input_min_read_length=75 input_max_read_length=75 processed_min_read_length=75 processed_max_read_length=75
2024-12-30 23:05:33.450571 INFO::io.R/saveWithID: saving file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads_single_end.358f3b4f1e70da/results/test_se.summary_preprocess.tab
2024-12-30 23:05:33.452371 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads_single_end.358f3b4f1e70da/bams/processed.aligner_input_1.fastq ...
2024-12-30 23:05:33.455654 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/bbs-3.20-bioc/tmpdir/RtmpWGWOi7/test.preprocessReads_single_end.358f3b4f1e70da/reports/shortReadReport_1 ...
2024-12-30 23:05:34.754172 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



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



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



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



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



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



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-12-30 23:05:35.341139 INFO::preprocessReads.R/preprocessReads: starting...
2024-12-30 23:05:35.359143 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-12-30 23:05:35.375634 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-12-30 23:05:35.378074 DEBUG::tools.R/processChunks: starting...
2024-12-30 23:05:38.457384 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-12-30 23:05:38.458725 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-12-30 23:05:41.301431 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-12-30 23:05:41.353375 DEBUG::tools.R/processChunks: done
2024-12-30 23:05:41.356102 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-12-30 23:05:41.357575 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-12-30 23:05:41.359089 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-12-30 23:05:41.360257 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-12-30 23:05:41.366242 INFO::preprocessReads.R/mergeSummaryPreprocess: total_reads=2500 highqual_reads=2500 adapter_contam=0 read_length=100 rRNA_contam_reads=0 processed_reads=2500 input_min_read_length=100 input_max_read_length=100 processed_min_read_length=71 processed_max_read_length=100
2024-12-30 23:05:41.367894 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-12-30 23:05:41.369941 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-12-30 23:05:41.374002 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-12-30 23:05:41.377721 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-12-30 23:06:35.369037 DEBUG::tools.R/traceMem: wired.mem=-76.255687 GiB
2024-12-30 23:07:35.435835 DEBUG::tools.R/traceMem: wired.mem=-68.841648 GiB
2024-12-30 23:08:35.501247 DEBUG::tools.R/traceMem: wired.mem=-71.687107 GiB
2024-12-30 23:09:35.56881 DEBUG::tools.R/traceMem: wired.mem=-72.573612 GiB
2024-12-30 23:10:35.633962 DEBUG::tools.R/traceMem: wired.mem=-72.800080 GiB
2024-12-30 23:11:35.701584 DEBUG::tools.R/traceMem: wired.mem=-67.473215 GiB
2024-12-30 23:12:35.768146 DEBUG::tools.R/traceMem: wired.mem=-64.033075 GiB
2024-12-30 23:13:35.832555 DEBUG::tools.R/traceMem: wired.mem=-65.720766 GiB
2024-12-30 23:14:35.898535 DEBUG::tools.R/traceMem: wired.mem=-72.872645 GiB
2024-12-30 23:15:35.964982 DEBUG::tools.R/traceMem: wired.mem=-71.594004 GiB
2024-12-30 23:16:36.030757 DEBUG::tools.R/traceMem: wired.mem=-68.943401 GiB
2024-12-30 23:17:36.095463 DEBUG::tools.R/traceMem: wired.mem=-70.506770 GiB
2024-12-30 23:18:36.16091 DEBUG::tools.R/traceMem: wired.mem=-77.242986 GiB
2024-12-30 23:19:36.19235 DEBUG::tools.R/traceMem: wired.mem=-65.634849 GiB
2024-12-30 23:20:36.25822 DEBUG::tools.R/traceMem: wired.mem=-65.006563 GiB
2024-12-30 23:21:36.324974 DEBUG::tools.R/traceMem: wired.mem=-72.306807 GiB
2024-12-30 23:22:36.393251 DEBUG::tools.R/traceMem: wired.mem=-80.794702 GiB
2024-12-30 23:23:36.458787 DEBUG::tools.R/traceMem: wired.mem=-79.393837 GiB
2024-12-30 23:24:36.525695 DEBUG::tools.R/traceMem: wired.mem=-80.571077 GiB
2024-12-30 23:25:36.590059 DEBUG::tools.R/traceMem: wired.mem=-79.613342 GiB
2024-12-30 23:26:36.655807 DEBUG::tools.R/traceMem: wired.mem=-77.730091 GiB
2024-12-30 23:27:36.721972 DEBUG::tools.R/traceMem: wired.mem=-80.092795 GiB
2024-12-30 23:28:36.78825 DEBUG::tools.R/traceMem: wired.mem=-81.568575 GiB
2024-12-30 23:29:36.852468 DEBUG::tools.R/traceMem: wired.mem=-76.093723 GiB
2024-12-30 23:30:36.917825 DEBUG::tools.R/traceMem: wired.mem=-65.317155 GiB
2024-12-30 23:31:36.923252 DEBUG::tools.R/traceMem: wired.mem=-68.324553 GiB
2024-12-30 23:32:36.98724 DEBUG::tools.R/traceMem: wired.mem=-70.993687 GiB
2024-12-30 23:33:37.052046 DEBUG::tools.R/traceMem: wired.mem=-73.535214 GiB
2024-12-30 23:34:37.117849 DEBUG::tools.R/traceMem: wired.mem=-66.527564 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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