Multiple platform build/check report for BioC 3.21 - CHECK results for HTSeqGenie on nebbiolo1

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo1	Linux (Ubuntu 24.04.1 LTS)	x86_64	R Under development (unstable) (2024-10-21 r87258) -- "Unsuffered Consequences"	4748
palomino7	Windows Server 2022 Datacenter	x64	R Under development (unstable) (2024-10-26 r87273 ucrt) -- "Unsuffered Consequences"	4459
lconway	macOS 12.7.1 Monterey	x86_64	R Under development (unstable) (2024-11-20 r87352) -- "Unsuffered Consequences"	4349
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 nebbiolo1

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.37.0

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

StartedAt: 2024-11-25 00:56:27 -0500 (Mon, 25 Nov 2024)

EndedAt: 2024-11-25 01:36:27 -0500 (Mon, 25 Nov 2024)

EllapsedTime: 2400.2 seconds

RetCode: None

Status: TIMEOUT

CheckDir: HTSeqGenie.Rcheck

Warnings: NA

Command output

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


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

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

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

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

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

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

Installation output

HTSeqGenie.Rcheck/00install.out

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


* installing to library ‘/home/biocbuild/bbs-3.21-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 Under development (unstable) (2024-10-21 r87258) -- "Unsuffered Consequences"
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
Loading required package: generics

Attaching package: 'generics'

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

    as.difftime, as.factor, as.ordered, intersect, is.element, setdiff,
    setequal, union


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, is.unsorted, lapply,
    mapply, match, mget, order, paste, pmax, pmax.int, pmin, pmin.int,
    rank, rbind, rownames, sapply, saveRDS, table, tapply, unique,
    unsplit, which.max, which.min

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

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

    findMatches

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

    I, expand.grid, unname

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

Attaching package: 'Biostrings'

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

    strsplit

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

Attaching package: 'MatrixGenerics'

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

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

Loading required package: Biobase
Welcome to Bioconductor

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


Attaching package: 'Biobase'

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

    rowMedians

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

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

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

    tabulate

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


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:04:58.117733 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-25 01:04:58.125174 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:04:58.128534 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-25 01:04:58.130573 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:05:00.450792 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:05:00.452101 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/chunks/chunk_000001/logs/progress.log
2024-11-25 01:05:03.124851 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-11-25 01:05:03.126195 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/chunks/chunk_000002/logs/progress.log
2024-11-25 01:05:05.793429 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-11-25 01:05:05.794719 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/chunks/chunk_000003/logs/progress.log
2024-11-25 01:05:08.443615 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-11-25 01:05:08.475335 DEBUG::tools.R/processChunks: done
2024-11-25 01:05:08.479192 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:05:08.48132 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/results/test_pe.adapter_contaminated_1.RData
2024-11-25 01:05:08.483984 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-25 01:05:08.485629 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/results/test_pe.adapter_contaminated_2.RData
2024-11-25 01:05:08.495553 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-11-25 01:05:08.497819 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/results/test_pe.summary_preprocess.tab
2024-11-25 01:05:08.500923 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/bams/processed.aligner_input_1.fastq ...
2024-11-25 01:05:08.506363 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/bams/processed.aligner_input_2.fastq ...
2024-11-25 01:05:08.510795 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/reports/shortReadReport_1 ...
2024-11-25 01:05:09.743471 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/reports/shortReadReport_2 ...
2024-11-25 01:05:11.771854 INFO::preprocessReads.R/preprocessReads: done
2024-11-25 01:05:11.845768 INFO::alignReads.R/alignReads: starting alignment...
2024-11-25 01:05:11.851502 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:05:14.229077 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:05:14.230623 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/chunks/chunk_000001/logs/progress.log
2024-11-25 01:05:16.965113 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-11-25 01:05:16.966655 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/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-11-25 01:05:19.60516 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-11-25 01:05:19.606939 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/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-11-25 01:05:22.224639 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-11-25 01:05:22.228542 DEBUG::tools.R/processChunks: done
2024-11-25 01:05:22.230843 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-11-25 01:05:22.454731 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-25 01:05:22.462955 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/results/test_pe.summary_alignment.tab
2024-11-25 01:05:22.469817 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/results/test_pe.summary_analyzed_bamstats.tab
2024-11-25 01:05:22.471405 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-25 01:05:22.705137 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.25e3824e61de/results/test_pe.summary_target_lengths.tab
2024-11-25 01:05:22.750253 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-25 01:05:22.751174 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:05:22.975295 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-25 01:05:22.978401 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:05:23.041337 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-11-25 01:05:23.045943 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:05:23.048779 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-25 01:05:23.050602 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:05:25.477284 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:05:25.478681 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/chunks/chunk_000001/logs/progress.log
2024-11-25 01:05:28.143173 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-11-25 01:05:28.14452 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/chunks/chunk_000002/logs/progress.log
2024-11-25 01:05:30.793875 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-11-25 01:05:30.795193 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/chunks/chunk_000003/logs/progress.log
2024-11-25 01:05:33.461779 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-11-25 01:05:33.463037 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/chunks/chunk_000004/logs/progress.log
2024-11-25 01:05:36.063576 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.043 minutes
2024-11-25 01:05:36.087356 DEBUG::tools.R/processChunks: done
2024-11-25 01:05:36.090447 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:05:36.092664 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/results/test_pe.adapter_contaminated_1.RData
2024-11-25 01:05:36.095602 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-25 01:05:36.097336 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/results/test_pe.adapter_contaminated_2.RData
2024-11-25 01:05:36.10739 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-11-25 01:05:36.109499 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/results/test_pe.summary_preprocess.tab
2024-11-25 01:05:36.112867 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/bams/processed.aligner_input_1.fastq ...
2024-11-25 01:05:36.117415 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/bams/processed.aligner_input_2.fastq ...
2024-11-25 01:05:36.121251 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/reports/shortReadReport_1 ...
2024-11-25 01:05:37.329134 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.alignReads.sparsechunks.25e3817f21ed5/reports/shortReadReport_2 ...
2024-11-25 01:05:39.424055 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:05:39.634909 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-11-25 01:05:39.639012 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -D /home/biocbuild/.local/share/gmap -t 1 -d TP53_demo_3.2.2 --quality-protocol=illumina  -A sam --read-group-id=test_se -m 0 --split-output /tmp/RtmpxA56HF/test.alignReadsOneSingleEnd.25e381124532b/bams/test.alignReads /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-11-25 01:05:39.851635 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-11-25 01:05:39.939417 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReadsOneSingleEnd.25e381124532b/results/test.alignReads.summary_alignment.tab
2024-11-25 01:05:39.984629 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.alignReadsOneSingleEnd.25e381124532b/results/test.alignReads.summary_analyzed_bamstats.tab
2024-11-25 01:05:39.986083 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:05:40.24981 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.genotype.25e384117bc74/results/test_pe.coverage.RData
2024-11-25 01:05:40.251473 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpxA56HF/test.genotype.25e384117bc74/results/test_pe.coverage.bw
2024-11-25 01:05:40.356696 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.genotype.25e384117bc74/results/test_pe.summary_coverage.tab
2024-11-25 01:05:40.358382 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-25 01:05:50.102424 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-25 01:05:50.179243 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-25 01:05:50.194503 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-25 01:05:50.195921 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.genotype.25e384117bc74/results/test_pe.raw_variants.RData
2024-11-25 01:05:50.198139 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.genotype.25e384117bc74/results/test_pe.filtered_variants.RData
2024-11-25 01:05:50.199434 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-25 01:05:50.200571 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-25 01:05:50.574975 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-25 01:05:50.576197 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-11-25 01:06:42.642833 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-25 01:06:43.015278 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-25 01:06:43.016083 INFO::analyzeVariants.R/.callGenotypes: done
[W::bcf_hdr_check_sanity] PL should be declared as Number=G
 done successfully.



Executing test function test.wrap.callVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:06:43.404862 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-25 01:06:52.930539 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-25 01:06:53.002081 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-25 01:06:53.017839 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-25 01:06:53.01912 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.25e3815779341/results/test_pe.raw_variants.RData
2024-11-25 01:06:53.021317 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.25e3815779341/results/test_pe.filtered_variants.RData
2024-11-25 01:06:53.022606 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:06:53.155056 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-25 01:07:02.349747 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-25 01:07:02.402837 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-25 01:07:02.418288 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-25 01:07:02.419587 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.filters.25e38637a83db/results/test_pe.raw_variants.RData
2024-11-25 01:07:02.421946 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.filters.25e38637a83db/results/test_pe.filtered_variants.RData
2024-11-25 01:07:02.423353 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-25 01:07:02.424652 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-25 01:07:11.775867 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-25 01:07:11.811631 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-25 01:07:11.826871 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-25 01:07:11.828134 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.filters.25e38637a83db/results/test_pe.raw_variants.RData
2024-11-25 01:07:11.830466 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.filters.25e38637a83db/results/test_pe.filtered_variants.RData
2024-11-25 01:07:11.832273 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:07:12.05797 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-25 01:07:12.059358 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-11-25 01:07:14.266211 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-25 01:07:14.32995 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-25 01:07:14.343841 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-25 01:07:14.345004 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.which.25e386b74374d/results/test_pe.raw_variants.RData
2024-11-25 01:07:14.346472 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.wrap.callVariants.which.25e386b74374d/results/test_pe.filtered_variants.RData
2024-11-25 01:07:14.347587 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:07:14.473661 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-25 01:07:14.474728 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:07:14.61939 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-25 01:07:14.794839 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-11-25 01:08:01.094475 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/rfyqkwai/merged/results/bla.coverage.RData
2024-11-25 01:08:01.096972 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpxA56HF/rfyqkwai/merged/results/bla.coverage.bw
2024-11-25 01:08:01.166966 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/rfyqkwai/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-11-25 01:08:02.087574 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/ostwuhfz/merged/results/bla.coverage.RData
2024-11-25 01:08:02.089016 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpxA56HF/ostwuhfz/merged/results/bla.coverage.bw
2024-11-25 01:08:02.09955 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/ostwuhfz/merged/results/bla.summary_coverage.tab
 done successfully.



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



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



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



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



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



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



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



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



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



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



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



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:03.24174 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-11-25 01:08:03.242739 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpxA56HF/test.detectRRNA.25e3833709af3/bams/rRNA_contam/input1.fastq
2024-11-25 01:08:03.24569 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/RtmpxA56HF/test.detectRRNA.25e3833709af3/bams/rRNA_contam/test_se /tmp/RtmpxA56HF/test.detectRRNA.25e3833709af3/bams/rRNA_contam/input1.fastq 2>&1
2024-11-25 01:08:03.371858 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-11-25 01:08:03.372889 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:03.51289 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-11-25 01:08:03.513842 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpxA56HF/test.detectRRNA.paired_end.25e386d1a90d/bams/rRNA_contam/input1.fastq
2024-11-25 01:08:03.51523 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpxA56HF/test.detectRRNA.paired_end.25e386d1a90d/bams/rRNA_contam/input2.fastq
2024-11-25 01:08:03.517249 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/RtmpxA56HF/test.detectRRNA.paired_end.25e386d1a90d/bams/rRNA_contam/test_pe /tmp/RtmpxA56HF/test.detectRRNA.paired_end.25e386d1a90d/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpxA56HF/test.detectRRNA.paired_end.25e386d1a90d/bams/rRNA_contam/input2.fastq 2>&1
2024-11-25 01:08:03.730037 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-11-25 01:08:03.730993 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



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



Executing test function test.getRRNAIds_random  ... 2024-11-25 01:08:03.977356 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/RtmpxA56HF/test_get_rRNAIds_randomvgwlqout/test_pe /tmp/RtmpxA56HF/test_get_rRNAIds_randomvgwlqout/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-11-25 01:08:04.202054 INFO::filterQuality.R/filterQuality: filterByLength...
2024-11-25 01:08:04.20342 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-11-25 01:08:04.204283 INFO::filterQuality.R/filterByLength: done
2024-11-25 01:08:04.247993 INFO::filterQuality.R/filterQuality: filterByLength...
2024-11-25 01:08:04.248873 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-11-25 01:08:04.249714 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-11-25 01:08:04.294725 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-25 01:08:04.302682 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-25 01:08:04.303624 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-25 01:08:04.307524 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-25 01:08:04.308407 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-25 01:08:04.312283 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-25 01:08:04.313177 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-25 01:08:04.316998 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:04.584872 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:04.586987 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.pefq.subsample  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:04.746176 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:04.831836 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-25 01:08:04.834427 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:04.836527 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:05.922115 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:06.05169 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:06.194939 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:06.260741 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-25 01:08:06.263085 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:06.265177 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:06.447703 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:06.48381 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-25 01:08:06.486069 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:06.488114 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



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



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



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:08:07.146905 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-25 01:08:07.152413 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:08:07.155643 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-25 01:08:07.157733 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:08:09.656573 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:08:09.657933 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000001/logs/progress.log
2024-11-25 01:08:12.201264 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-11-25 01:08:12.20267 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000002/logs/progress.log
2024-11-25 01:08:14.739097 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-11-25 01:08:14.740725 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000003/logs/progress.log
2024-11-25 01:08:17.276695 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2024-11-25 01:08:17.318419 DEBUG::tools.R/processChunks: done
2024-11-25 01:08:17.323309 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:08:17.325339 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.adapter_contaminated_1.RData
2024-11-25 01:08:17.327513 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-25 01:08:17.329068 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.adapter_contaminated_2.RData
2024-11-25 01:08:17.337345 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-11-25 01:08:17.339172 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.summary_preprocess.tab
2024-11-25 01:08:17.341533 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/bams/processed.aligner_input_1.fastq ...
2024-11-25 01:08:17.34574 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/bams/processed.aligner_input_2.fastq ...
2024-11-25 01:08:17.348645 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/reports/shortReadReport_1 ...
2024-11-25 01:08:18.600796 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/reports/shortReadReport_2 ...
2024-11-25 01:08:19.591937 INFO::preprocessReads.R/preprocessReads: done
2024-11-25 01:08:19.685606 INFO::alignReads.R/alignReads: starting alignment...
2024-11-25 01:08:19.689672 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:08:22.177021 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:08:22.178597 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000001/logs/progress.log
2024-11-25 01:08:24.732516 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-11-25 01:08:24.734302 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/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-11-25 01:08:27.312859 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-11-25 01:08:27.315099 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/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-11-25 01:08:29.894844 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-11-25 01:08:29.898434 DEBUG::tools.R/processChunks: done
2024-11-25 01:08:29.900549 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-11-25 01:08:30.084564 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-25 01:08:30.09182 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.summary_alignment.tab
2024-11-25 01:08:30.098373 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.summary_analyzed_bamstats.tab
2024-11-25 01:08:30.10009 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-25 01:08:30.315708 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.summary_target_lengths.tab
2024-11-25 01:08:30.361035 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-25 01:08:30.362019 INFO::alignReads.R/alignReads: done
2024-11-25 01:08:30.466342 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-11-25 01:08:30.484746 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:08:33.098435 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:08:33.1001 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000001/logs/progress.log
2024-11-25 01:08:35.530183 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-11-25 01:08:35.532991 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000002/logs/progress.log
2024-11-25 01:08:37.936507 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2024-11-25 01:08:37.93818 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000003/logs/progress.log
2024-11-25 01:08:40.380904 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2024-11-25 01:08:40.384633 DEBUG::tools.R/processChunks: done
2024-11-25 01:08:40.386918 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-11-25 01:08:40.406462 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.counts_exon.tab
2024-11-25 01:08:40.422538 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.counts_exon_disjoint.tab
2024-11-25 01:08:40.43404 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.counts_gene.tab
2024-11-25 01:08:40.442353 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.counts_gene_coding.tab
2024-11-25 01:08:40.449718 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.counts_gene_exonic.tab
2024-11-25 01:08:40.457334 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.counts_intergenic.tab
2024-11-25 01:08:40.471903 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.counts_intron.tab
2024-11-25 01:08:40.476488 INFO::countGenomicFeatures.R/mergeCounts: done
2024-11-25 01:08:40.48475 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.summary_counts.tab
2024-11-25 01:08:40.487264 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-11-25 01:08:40.788789 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-11-25 01:08:40.789806 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-11-25 01:08:40.896424 INFO::coverage.R/calculateCoverage: starting...
2024-11-25 01:08:40.900513 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:08:43.60849 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:08:43.610214 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000001/logs/progress.log
2024-11-25 01:08:45.771955 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-11-25 01:08:45.773526 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000002/logs/progress.log
2024-11-25 01:08:47.936428 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-11-25 01:08:47.937976 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/chunks/chunk_000003/logs/progress.log
2024-11-25 01:08:50.109751 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2024-11-25 01:08:50.113017 DEBUG::tools.R/processChunks: done
2024-11-25 01:08:51.99222 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.coverage.RData
2024-11-25 01:08:51.994046 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.coverage.bw
2024-11-25 01:08:52.00805 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.summary_coverage.tab
2024-11-25 01:08:52.009589 INFO::coverage.R/calculateCoverage: done
2024-11-25 01:08:52.012105 INFO::analyzeVariants/analyzeVariants: starting ...
2024-11-25 01:08:52.112837 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-25 01:08:54.834659 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-25 01:08:54.900935 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-25 01:08:54.915689 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-25 01:08:54.916941 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.raw_variants.RData
2024-11-25 01:08:54.918456 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.filtered_variants.RData
2024-11-25 01:08:54.919636 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-25 01:08:54.920591 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-25 01:08:55.117882 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-25 01:08:55.20826 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/results/test_pe.summary_variants.tab
2024-11-25 01:08:55.21025 INFO::analyzeVariants/analyzeVariants: done
2024-11-25 01:08:55.214935 INFO::Pipeline run successful.
2024-11-25 01:08:55.384537 INFO::mergeLanes.R/doMergeLanes: starting...
2024-11-25 01:08:55.388922 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:08:55.390979 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.adapter_contaminated_1.RData
2024-11-25 01:08:55.393552 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-25 01:08:55.395398 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.adapter_contaminated_2.RData
2024-11-25 01:08:55.406304 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-11-25 01:08:55.408378 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.summary_preprocess.tab
2024-11-25 01:08:55.410397 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-11-25 01:08:55.627229 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-25 01:08:55.633669 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.summary_alignment.tab
2024-11-25 01:08:55.641068 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.summary_analyzed_bamstats.tab
2024-11-25 01:08:55.642938 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-25 01:08:55.86939 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.summary_target_lengths.tab
2024-11-25 01:08:55.918002 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-25 01:08:55.955705 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-11-25 01:08:55.974427 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.counts_exon.tab
2024-11-25 01:08:55.985464 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.counts_exon_disjoint.tab
2024-11-25 01:08:55.991692 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.counts_gene.tab
2024-11-25 01:08:55.996732 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.counts_gene_coding.tab
2024-11-25 01:08:56.001751 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.counts_gene_exonic.tab
2024-11-25 01:08:56.007098 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.counts_intergenic.tab
2024-11-25 01:08:56.017728 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.counts_intron.tab
2024-11-25 01:08:56.020289 INFO::countGenomicFeatures.R/mergeCounts: done
2024-11-25 01:08:56.026188 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.summary_counts.tab
2024-11-25 01:08:56.027771 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-11-25 01:08:56.257264 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-11-25 01:08:57.912724 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.coverage.RData
2024-11-25 01:08:57.915073 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.coverage.bw
2024-11-25 01:08:57.925528 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.summary_coverage.tab
2024-11-25 01:08:57.965145 INFO::analyzeVariants/analyzeVariants: starting ...
2024-11-25 01:08:58.035351 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-25 01:09:00.622627 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-25 01:09:00.69229 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-25 01:09:00.708074 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-25 01:09:00.709521 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.raw_variants.RData
2024-11-25 01:09:00.711123 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.filtered_variants.RData
2024-11-25 01:09:00.712363 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-25 01:09:00.713322 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-25 01:09:00.923381 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-25 01:09:01.019748 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.mergeLanes.25e3840453053/merged/results/merged.summary_variants.tab
2024-11-25 01:09:01.021724 INFO::analyzeVariants/analyzeVariants: done
2024-11-25 01:09:01.024137 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0 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 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= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:09:01.299939 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-25 01:09:01.306214 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:09:01.30976 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-25 01:09:01.31207 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:09:03.981313 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:09:03.982689 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/chunks/chunk_000001/logs/progress.log
2024-11-25 01:09:06.52211 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-11-25 01:09:06.562352 DEBUG::tools.R/processChunks: done
2024-11-25 01:09:06.564509 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:09:06.566041 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/results/test_pe.adapter_contaminated_1.RData
2024-11-25 01:09:06.56769 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-25 01:09:06.569091 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/results/test_pe.adapter_contaminated_2.RData
2024-11-25 01:09:06.575145 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-11-25 01:09:06.576838 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/results/test_pe.summary_preprocess.tab
2024-11-25 01:09:06.578684 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/bams/processed.aligner_input_1.fastq ...
2024-11-25 01:09:06.582068 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/bams/processed.aligner_input_2.fastq ...
2024-11-25 01:09:06.584997 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/reports/shortReadReport_1 ...
2024-11-25 01:09:07.855781 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.preprocessReads.25e381e9f1a92/reports/shortReadReport_2 ...
2024-11-25 01:09:08.883367 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:09:09.130676 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-25 01:09:09.136837 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:09:09.140325 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-11-25 01:09:09.1426 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:09:11.772543 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:09:11.774011 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/chunks/chunk_000001/logs/progress.log
2024-11-25 01:09:14.317401 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-11-25 01:09:14.318931 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/chunks/chunk_000002/logs/progress.log
2024-11-25 01:09:16.902139 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-11-25 01:09:16.903945 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/chunks/chunk_000003/logs/progress.log
2024-11-25 01:09:19.448298 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2024-11-25 01:09:19.484552 DEBUG::tools.R/processChunks: done
2024-11-25 01:09:19.48709 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:09:19.488731 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/results/test_pe.adapter_contaminated_1.RData
2024-11-25 01:09:19.490735 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-25 01:09:19.492281 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/results/test_pe.adapter_contaminated_2.RData
2024-11-25 01:09:19.499824 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-11-25 01:09:19.501461 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/results/test_pe.summary_preprocess.tab
2024-11-25 01:09:19.503652 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/bams/processed.aligner_input_1.fastq ...
2024-11-25 01:09:19.507625 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/bams/processed.aligner_input_2.fastq ...
2024-11-25 01:09:19.511365 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/reports/shortReadReport_1 ...
2024-11-25 01:09:20.737373 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.preprocessReads.minichunks.25e3850a638a9/reports/shortReadReport_2 ...
2024-11-25 01:09:21.777763 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpxA56HF/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:09:22.066773 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-25 01:09:22.085839 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-11-25 01:09:22.088333 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:09:24.936954 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:09:24.93835 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpxA56HF/test.preprocessReads_single_end.25e3851c74680/chunks/chunk_000001/logs/progress.log
2024-11-25 01:09:27.272542 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-11-25 01:09:27.28166 DEBUG::tools.R/processChunks: done
2024-11-25 01:09:27.283761 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:09:27.285223 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads_single_end.25e3851c74680/results/test_se.adapter_contaminated_1.RData
2024-11-25 01:09:27.291265 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-11-25 01:09:27.29295 INFO::io.R/saveWithID: saving file= /tmp/RtmpxA56HF/test.preprocessReads_single_end.25e3851c74680/results/test_se.summary_preprocess.tab
2024-11-25 01:09:27.294703 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpxA56HF/test.preprocessReads_single_end.25e3851c74680/bams/processed.aligner_input_1.fastq ...
2024-11-25 01:09:27.298401 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpxA56HF/test.preprocessReads_single_end.25e3851c74680/reports/shortReadReport_1 ...
2024-11-25 01:09:28.523433 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.21-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-11-25 01:09:29.144949 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-25 01:09:29.151166 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-11-25 01:09:29.155596 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.21-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-11-25 01:09:29.157785 DEBUG::tools.R/processChunks: starting...
2024-11-25 01:09:31.778972 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-25 01:09:31.780435 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-11-25 01:09:34.478495 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-11-25 01:09:34.540847 DEBUG::tools.R/processChunks: done
2024-11-25 01:09:34.544179 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-25 01:09:34.546678 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-11-25 01:09:34.549381 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-25 01:09:34.551741 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-11-25 01:09:34.56132 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-11-25 01:09:34.564119 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-11-25 01:09:34.567083 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-11-25 01:09:34.572021 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-11-25 01:09:34.576285 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-11-25 01:10:29.176143 DEBUG::tools.R/traceMem: wired.mem=-10.919961 GiB
2024-11-25 01:11:29.242606 DEBUG::tools.R/traceMem: wired.mem=-4.760576 GiB
2024-11-25 01:12:29.310496 DEBUG::tools.R/traceMem: wired.mem=-8.251875 GiB
2024-11-25 01:13:29.378023 DEBUG::tools.R/traceMem: wired.mem=-12.373402 GiB
2024-11-25 01:14:29.443533 DEBUG::tools.R/traceMem: wired.mem=-8.421024 GiB
2024-11-25 01:15:29.510929 DEBUG::tools.R/traceMem: wired.mem=-6.855598 GiB
2024-11-25 01:16:29.577554 DEBUG::tools.R/traceMem: wired.mem=-12.732588 GiB
2024-11-25 01:17:29.642648 DEBUG::tools.R/traceMem: wired.mem=-14.955340 GiB
2024-11-25 01:18:29.708165 DEBUG::tools.R/traceMem: wired.mem=-11.769324 GiB
2024-11-25 01:19:29.775657 DEBUG::tools.R/traceMem: wired.mem=-4.681302 GiB
2024-11-25 01:20:29.842147 DEBUG::tools.R/traceMem: wired.mem=-0.394600 GiB
2024-11-25 01:21:29.906078 DEBUG::tools.R/traceMem: wired.mem=-0.725180 GiB
2024-11-25 01:22:29.971766 DEBUG::tools.R/traceMem: wired.mem=-6.010692 GiB
2024-11-25 01:23:30.036813 DEBUG::tools.R/traceMem: wired.mem=-10.422043 GiB
2024-11-25 01:24:30.104539 DEBUG::tools.R/traceMem: wired.mem=-5.320753 GiB
2024-11-25 01:25:30.169023 DEBUG::tools.R/traceMem: wired.mem=-10.376167 GiB
2024-11-25 01:26:30.234381 DEBUG::tools.R/traceMem: wired.mem=1.540964 GiB
2024-11-25 01:27:30.300539 DEBUG::tools.R/traceMem: wired.mem=4.078772 GiB
2024-11-25 01:28:30.366799 DEBUG::tools.R/traceMem: wired.mem=-1.171800 GiB
2024-11-25 01:29:30.43385 DEBUG::tools.R/traceMem: wired.mem=-0.325149 GiB
2024-11-25 01:30:30.502325 DEBUG::tools.R/traceMem: wired.mem=-3.211141 GiB
2024-11-25 01:31:30.569409 DEBUG::tools.R/traceMem: wired.mem=-7.086801 GiB
2024-11-25 01:32:30.634812 DEBUG::tools.R/traceMem: wired.mem=-5.745713 GiB
2024-11-25 01:33:30.701795 DEBUG::tools.R/traceMem: wired.mem=-4.453433 GiB
2024-11-25 01:34:30.76868 DEBUG::tools.R/traceMem: wired.mem=-5.615124 GiB
2024-11-25 01:35:30.800519 DEBUG::tools.R/traceMem: wired.mem=-1.855103 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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