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

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo1	Linux (Ubuntu 22.04.3 LTS)	x86_64	R Under development (unstable) (2024-03-18 r86148) -- "Unsuffered Consequences"	4708
palomino3	Windows Server 2022 Datacenter	x64	R Under development (unstable) (2024-03-16 r86144 ucrt) -- "Unsuffered Consequences"	4446
lconway	macOS 12.7.1 Monterey	x86_64	R Under development (unstable) (2024-03-18 r86148) -- "Unsuffered Consequences"	4471
kunpeng2	Linux (openEuler 22.03 LTS-SP1)	aarch64	R Under development (unstable) (2024-03-19 r86153) -- "Unsuffered Consequences"	4426
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*

Package: HTSeqGenie

Version: 4.33.0

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

StartedAt: 2024-03-27 23:23:26 -0400 (Wed, 27 Mar 2024)

EndedAt: 2024-03-27 23:37:26 -0400 (Wed, 27 Mar 2024)

EllapsedTime: 840.1 seconds

RetCode: 0

Status: OK

CheckDir: HTSeqGenie.Rcheck

Warnings: 0

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


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

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

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

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

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

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

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

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


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


R Under development (unstable) (2024-03-18 r86148) -- "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

Attaching package: 'BiocGenerics'

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

    IQR, mad, sd, var, xtabs

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

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

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

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

    findMatches

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

    I, expand.grid, unname

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

Attaching package: 'Biostrings'

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

    strsplit

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

Attaching package: 'MatrixGenerics'

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

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

Loading required package: Biobase
Welcome to Bioconductor

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


Attaching package: 'Biobase'

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

    rowMedians

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

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

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

    tabulate

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


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:29:13.505408 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:29:13.514337 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:29:13.517941 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:29:13.5203 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:29:16.28346 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:29:16.285043 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/chunks/chunk_000001/logs/progress.log
2024-03-27 23:29:19.030757 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:19.03229 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/chunks/chunk_000002/logs/progress.log
2024-03-27 23:29:21.769191 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:21.770659 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/chunks/chunk_000003/logs/progress.log
2024-03-27 23:29:24.514699 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:24.549138 DEBUG::tools.R/processChunks: done
2024-03-27 23:29:24.554124 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:29:24.556666 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:29:24.559686 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:29:24.561473 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:29:24.571176 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-03-27 23:29:24.573417 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/results/test_pe.summary_preprocess.tab
2024-03-27 23:29:24.576751 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:29:24.580741 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:29:24.5847 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/reports/shortReadReport_1 ...
2024-03-27 23:29:25.933248 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/reports/shortReadReport_2 ...
2024-03-27 23:29:28.092903 INFO::preprocessReads.R/preprocessReads: done
2024-03-27 23:29:28.144506 INFO::alignReads.R/alignReads: starting alignment...
2024-03-27 23:29:28.151335 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:29:30.934062 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:29:30.935824 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/chunks/chunk_000001/logs/progress.log
2024-03-27 23:29:33.697549 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:33.699195 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/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.
2024-03-27 23:29:36.329218 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-03-27 23:29:36.331154 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/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-03-27 23:29:38.99944 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-03-27 23:29:39.002023 DEBUG::tools.R/processChunks: done
2024-03-27 23:29:39.003482 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:29:39.20859 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:29:39.217884 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/results/test_pe.summary_alignment.tab
2024-03-27 23:29:39.225184 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/results/test_pe.summary_analyzed_bamstats.tab
2024-03-27 23:29:39.226939 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:29:39.473322 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.3a9cefde4ecc2/results/test_pe.summary_target_lengths.tab
2024-03-27 23:29:39.519801 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:29:39.520845 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:29:39.747894 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:29:39.752002 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:29:39.82761 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-03-27 23:29:39.832903 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:29:39.835999 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:29:39.83798 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:29:42.732525 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:29:42.734091 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/chunks/chunk_000001/logs/progress.log
2024-03-27 23:29:45.492931 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:45.494437 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/chunks/chunk_000002/logs/progress.log
2024-03-27 23:29:48.172237 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-03-27 23:29:48.173788 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/chunks/chunk_000003/logs/progress.log
2024-03-27 23:29:50.958007 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:50.959623 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/chunks/chunk_000004/logs/progress.log
2024-03-27 23:29:53.648381 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2024-03-27 23:29:53.682237 DEBUG::tools.R/processChunks: done
2024-03-27 23:29:53.685881 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:29:53.688733 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:29:53.69214 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:29:53.69398 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:29:53.704736 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-03-27 23:29:53.706942 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/results/test_pe.summary_preprocess.tab
2024-03-27 23:29:53.710617 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:29:53.714796 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:29:53.718656 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/reports/shortReadReport_1 ...
2024-03-27 23:29:55.060956 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.alignReads.sparsechunks.3a9cefc288385/reports/shortReadReport_2 ...
2024-03-27 23:29:57.308897 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:29:57.508153 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-03-27 23:29:57.513204 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/Rtmp4jDZEH/test.alignReadsOneSingleEnd.3a9cef5814e49d/bams/test.alignReads /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-03-27 23:29:57.747688 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-03-27 23:29:57.845934 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReadsOneSingleEnd.3a9cef5814e49d/results/test.alignReads.summary_alignment.tab
2024-03-27 23:29:57.90571 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.alignReadsOneSingleEnd.3a9cef5814e49d/results/test.alignReads.summary_analyzed_bamstats.tab
2024-03-27 23:29:57.907471 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:29:58.230637 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.genotype.3a9cef49de4bda/results/test_pe.coverage.RData
2024-03-27 23:29:58.233101 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4jDZEH/test.genotype.3a9cef49de4bda/results/test_pe.coverage.bw
2024-03-27 23:29:58.348825 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.genotype.3a9cef49de4bda/results/test_pe.summary_coverage.tab
2024-03-27 23:29:58.350676 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:30:08.648877 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:30:08.731962 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:30:08.752697 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:30:08.754385 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.genotype.3a9cef49de4bda/results/test_pe.raw_variants.RData
2024-03-27 23:30:08.757024 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.genotype.3a9cef49de4bda/results/test_pe.filtered_variants.RData
2024-03-27 23:30:08.758485 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:30:08.759799 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:30:09.179892 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:30:09.181253 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-03-27 23:31:06.765835 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:31:07.175617 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:31:07.176538 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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:07.572428 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:17.63108 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:17.705773 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:17.722503 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:17.723926 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.3a9cef508dd83d/results/test_pe.raw_variants.RData
2024-03-27 23:31:17.726396 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.3a9cef508dd83d/results/test_pe.filtered_variants.RData
2024-03-27 23:31:17.727805 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:17.873804 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:27.603184 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:27.658897 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:27.675058 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:27.676444 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.filters.3a9cef53bb62de/results/test_pe.raw_variants.RData
2024-03-27 23:31:27.678815 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.filters.3a9cef53bb62de/results/test_pe.filtered_variants.RData
2024-03-27 23:31:27.680109 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:31:27.681613 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:37.584774 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:37.624517 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:37.64211 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:37.643727 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.filters.3a9cef53bb62de/results/test_pe.raw_variants.RData
2024-03-27 23:31:37.646595 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.filters.3a9cef53bb62de/results/test_pe.filtered_variants.RData
2024-03-27 23:31:37.648694 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:37.885686 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:37.887301 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-03-27 23:31:40.363826 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:40.437479 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:40.453492 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:40.454777 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.which.3a9cef4179663a/results/test_pe.raw_variants.RData
2024-03-27 23:31:40.456333 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.wrap.callVariants.which.3a9cef4179663a/results/test_pe.filtered_variants.RData
2024-03-27 23:31:40.457561 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:40.591352 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:31:40.592657 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:40.763492 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:31:40.975753 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-03-27 23:32:36.84552 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/vzsgnitr/merged/results/bla.coverage.RData
2024-03-27 23:32:36.848697 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4jDZEH/vzsgnitr/merged/results/bla.coverage.bw
2024-03-27 23:32:36.92613 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/vzsgnitr/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-03-27 23:32:38.067029 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/ptqblgay/merged/results/bla.coverage.RData
2024-03-27 23:32:38.06862 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4jDZEH/ptqblgay/merged/results/bla.coverage.bw
2024-03-27 23:32:38.080707 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/ptqblgay/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:39.336592 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-03-27 23:32:39.337828 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4jDZEH/test.detectRRNA.3a9cef11019059/bams/rRNA_contam/input1.fastq
2024-03-27 23:32:39.34121 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/Rtmp4jDZEH/test.detectRRNA.3a9cef11019059/bams/rRNA_contam/test_se /tmp/Rtmp4jDZEH/test.detectRRNA.3a9cef11019059/bams/rRNA_contam/input1.fastq 2>&1
2024-03-27 23:32:39.612703 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-03-27 23:32:39.613884 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:39.740765 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-03-27 23:32:39.741824 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4jDZEH/test.detectRRNA.paired_end.3a9cef339b46df/bams/rRNA_contam/input1.fastq
2024-03-27 23:32:39.743389 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmp4jDZEH/test.detectRRNA.paired_end.3a9cef339b46df/bams/rRNA_contam/input2.fastq
2024-03-27 23:32:39.745574 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/Rtmp4jDZEH/test.detectRRNA.paired_end.3a9cef339b46df/bams/rRNA_contam/test_pe /tmp/Rtmp4jDZEH/test.detectRRNA.paired_end.3a9cef339b46df/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmp4jDZEH/test.detectRRNA.paired_end.3a9cef339b46df/bams/rRNA_contam/input2.fastq 2>&1
2024-03-27 23:32:40.04549 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-03-27 23:32:40.046624 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-03-27 23:32:40.067318 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/Rtmp4jDZEH/test_get_rRNA_idsictmpefv/test_pe /tmp/Rtmp4jDZEH/test_get_rRNA_idsictmpefv/1.fastq -a paired /tmp/Rtmp4jDZEH/test_get_rRNA_idsictmpefv/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-03-27 23:32:40.373817 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/Rtmp4jDZEH/test_get_rRNAIds_randomapsxnybd/test_pe /tmp/Rtmp4jDZEH/test_get_rRNAIds_randomapsxnybd/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-03-27 23:32:40.659253 INFO::filterQuality.R/filterQuality: filterByLength...
2024-03-27 23:32:40.660782 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-03-27 23:32:40.66169 INFO::filterQuality.R/filterByLength: done
2024-03-27 23:32:40.708875 INFO::filterQuality.R/filterQuality: filterByLength...
2024-03-27 23:32:40.709924 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-03-27 23:32:40.710779 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-03-27 23:32:40.761769 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:40.770739 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-03-27 23:32:40.77194 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:40.776547 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-03-27 23:32:40.777592 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:40.781932 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-03-27 23:32:40.782866 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:40.787087 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:41.041899 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:41.04419 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:41.187478 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:41.259199 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-03-27 23:32:41.261942 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:41.264113 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:41.457682 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:41.596883 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:41.77225 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:41.828423 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-03-27 23:32:41.831007 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:41.833409 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:43.106108 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:43.147934 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-03-27 23:32:43.150512 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:43.153021 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-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/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:43.79 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:32:43.796918 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:43.800928 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:32:43.803638 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:32:47.046927 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:32:47.048521 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000001/logs/progress.log
2024-03-27 23:32:49.706097 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-03-27 23:32:49.707624 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000002/logs/progress.log
2024-03-27 23:32:52.305531 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-03-27 23:32:52.307038 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000003/logs/progress.log
2024-03-27 23:32:55.12872 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2024-03-27 23:32:55.187766 DEBUG::tools.R/processChunks: done
2024-03-27 23:32:55.190964 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:32:55.192704 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:32:55.19484 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:32:55.196494 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:32:55.205769 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-03-27 23:32:55.208146 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.summary_preprocess.tab
2024-03-27 23:32:55.211204 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:32:55.216956 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:32:55.220648 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/reports/shortReadReport_1 ...
2024-03-27 23:32:56.558091 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/reports/shortReadReport_2 ...
2024-03-27 23:32:57.586712 INFO::preprocessReads.R/preprocessReads: done
2024-03-27 23:32:57.675011 INFO::alignReads.R/alignReads: starting alignment...
2024-03-27 23:32:57.680095 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:33:01.452482 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:33:01.454456 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000001/logs/progress.log
2024-03-27 23:33:04.041291 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-03-27 23:33:04.043054 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/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.
2024-03-27 23:33:06.678132 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-03-27 23:33:06.680021 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/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-03-27 23:33:09.298979 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-03-27 23:33:09.301329 DEBUG::tools.R/processChunks: done
2024-03-27 23:33:09.302752 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:33:09.488157 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:33:09.496072 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.summary_alignment.tab
2024-03-27 23:33:09.502848 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.summary_analyzed_bamstats.tab
2024-03-27 23:33:09.504816 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:33:09.731918 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.summary_target_lengths.tab
2024-03-27 23:33:09.778631 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:33:09.77968 INFO::alignReads.R/alignReads: done
2024-03-27 23:33:09.879457 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-03-27 23:33:09.899117 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:33:12.772165 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:33:12.77397 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000001/logs/progress.log
2024-03-27 23:33:15.203932 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-03-27 23:33:15.205658 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000002/logs/progress.log
2024-03-27 23:33:17.671264 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2024-03-27 23:33:17.673125 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000003/logs/progress.log
2024-03-27 23:33:20.081659 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.04 minutes
2024-03-27 23:33:20.085264 DEBUG::tools.R/processChunks: done
2024-03-27 23:33:20.087611 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-03-27 23:33:20.109775 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.counts_exon.tab
2024-03-27 23:33:20.129612 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.counts_exon_disjoint.tab
2024-03-27 23:33:20.141261 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.counts_gene.tab
2024-03-27 23:33:20.149166 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.counts_gene_coding.tab
2024-03-27 23:33:20.157144 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.counts_gene_exonic.tab
2024-03-27 23:33:20.165315 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.counts_intergenic.tab
2024-03-27 23:33:20.180161 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.counts_intron.tab
2024-03-27 23:33:20.186745 INFO::countGenomicFeatures.R/mergeCounts: done
2024-03-27 23:33:20.195438 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.summary_counts.tab
2024-03-27 23:33:20.197855 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-03-27 23:33:20.497905 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-03-27 23:33:20.498977 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-03-27 23:33:20.580869 INFO::coverage.R/calculateCoverage: starting...
2024-03-27 23:33:20.586654 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:33:23.696774 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:33:23.698694 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000001/logs/progress.log
2024-03-27 23:33:25.89966 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2024-03-27 23:33:25.901691 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000002/logs/progress.log
2024-03-27 23:33:28.074615 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-03-27 23:33:28.076541 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/chunks/chunk_000003/logs/progress.log
2024-03-27 23:33:30.283711 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2024-03-27 23:33:30.286773 DEBUG::tools.R/processChunks: done
2024-03-27 23:33:32.212541 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.coverage.RData
2024-03-27 23:33:32.214788 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.coverage.bw
2024-03-27 23:33:32.22875 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.summary_coverage.tab
2024-03-27 23:33:32.230205 INFO::coverage.R/calculateCoverage: done
2024-03-27 23:33:32.232563 INFO::analyzeVariants/analyzeVariants: starting ...
2024-03-27 23:33:32.318637 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:33:35.38834 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:33:35.456994 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:33:35.472383 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:33:35.473817 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.raw_variants.RData
2024-03-27 23:33:35.475439 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.filtered_variants.RData
2024-03-27 23:33:35.4767 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:33:35.477697 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:33:35.685351 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:33:35.782627 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/results/test_pe.summary_variants.tab
2024-03-27 23:33:35.784979 INFO::analyzeVariants/analyzeVariants: done
2024-03-27 23:33:35.790295 INFO::Pipeline run successful.
2024-03-27 23:33:35.958859 INFO::mergeLanes.R/doMergeLanes: starting...
2024-03-27 23:33:35.964644 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:33:35.967268 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.adapter_contaminated_1.RData
2024-03-27 23:33:35.970388 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:33:35.972575 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.adapter_contaminated_2.RData
2024-03-27 23:33:35.985902 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-03-27 23:33:35.988487 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.summary_preprocess.tab
2024-03-27 23:33:35.991026 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:33:36.242917 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:33:36.250627 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.summary_alignment.tab
2024-03-27 23:33:36.258645 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.summary_analyzed_bamstats.tab
2024-03-27 23:33:36.26088 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:33:36.514976 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.summary_target_lengths.tab
2024-03-27 23:33:36.568389 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:33:36.612108 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-03-27 23:33:36.634949 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.counts_exon.tab
2024-03-27 23:33:36.648894 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.counts_exon_disjoint.tab
2024-03-27 23:33:36.657056 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.counts_gene.tab
2024-03-27 23:33:36.663142 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.counts_gene_coding.tab
2024-03-27 23:33:36.669088 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.counts_gene_exonic.tab
2024-03-27 23:33:36.67547 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.counts_intergenic.tab
2024-03-27 23:33:36.687725 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.counts_intron.tab
2024-03-27 23:33:36.691331 INFO::countGenomicFeatures.R/mergeCounts: done
2024-03-27 23:33:36.697916 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.summary_counts.tab
2024-03-27 23:33:36.699872 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-03-27 23:33:36.921526 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-03-27 23:33:38.97313 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.coverage.RData
2024-03-27 23:33:38.975993 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.coverage.bw
2024-03-27 23:33:38.987651 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.summary_coverage.tab
2024-03-27 23:33:39.024655 INFO::analyzeVariants/analyzeVariants: starting ...
2024-03-27 23:33:39.08956 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:33:42.254785 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:33:42.327471 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:33:42.344738 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:33:42.346353 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.raw_variants.RData
2024-03-27 23:33:42.348284 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.filtered_variants.RData
2024-03-27 23:33:42.349757 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:33:42.350898 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:33:42.574407 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:33:42.671918 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.mergeLanes.3a9cef27a5025/merged/results/merged.summary_variants.tab
2024-03-27 23:33:42.674156 INFO::analyzeVariants/analyzeVariants: done
2024-03-27 23:33:42.677775 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0 0.001 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
Error in DEACTIVATED("Skipped markDuplicates() test") : 
  Skipped markDuplicates() test
 done successfully.



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:33:42.990675 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:33:43.014684 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:33:43.034584 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:33:43.037728 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:33:49.637992 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:33:49.658166 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/chunks/chunk_000001/logs/progress.log
2024-03-27 23:33:54.326578 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.078 minutes
2024-03-27 23:33:54.488784 DEBUG::tools.R/processChunks: done
2024-03-27 23:33:54.493086 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:33:54.495885 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:33:54.499012 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:33:54.501633 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:33:54.512943 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-03-27 23:33:54.51604 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/results/test_pe.summary_preprocess.tab
2024-03-27 23:33:54.519499 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:33:54.551046 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:33:54.582747 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/reports/shortReadReport_1 ...
2024-03-27 23:34:00.464454 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.preprocessReads.3a9cef3a6be516/reports/shortReadReport_2 ...
2024-03-27 23:34:03.609 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:34:04.291267 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:34:04.303113 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:34:04.310282 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:34:04.315346 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:08.503146 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:08.504726 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:11.412558 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2024-03-27 23:34:11.416251 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/chunks/chunk_000002/logs/progress.log
2024-03-27 23:34:14.69661 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.055 minutes
2024-03-27 23:34:14.700643 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/chunks/chunk_000003/logs/progress.log
2024-03-27 23:34:17.990992 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.055 minutes
2024-03-27 23:34:18.163306 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:18.17106 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:34:18.175122 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:34:18.180105 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:34:18.183605 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:34:18.205902 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-03-27 23:34:18.211165 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/results/test_pe.summary_preprocess.tab
2024-03-27 23:34:18.218132 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:34:18.227893 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:34:18.236078 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/reports/shortReadReport_1 ...
2024-03-27 23:34:21.431078 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.preprocessReads.minichunks.3a9cef7e922283/reports/shortReadReport_2 ...
2024-03-27 23:34:24.481642 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:34:25.104824 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:34:25.175081 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:34:25.181725 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:30.973704 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:30.97614 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmp4jDZEH/test.preprocessReads_single_end.3a9cef46a43fd/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:33.510544 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-03-27 23:34:33.56638 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:33.57021 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:34:33.572282 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads_single_end.3a9cef46a43fd/results/test_se.adapter_contaminated_1.RData
2024-03-27 23:34:33.579722 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-03-27 23:34:33.581779 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.preprocessReads_single_end.3a9cef46a43fd/results/test_se.summary_preprocess.tab
2024-03-27 23:34:33.584063 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmp4jDZEH/test.preprocessReads_single_end.3a9cef46a43fd/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:34:33.587891 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmp4jDZEH/test.preprocessReads_single_end.3a9cef46a43fd/reports/shortReadReport_1 ...
2024-03-27 23:34:35.052226 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.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:34:35.755666 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:34:35.776611 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-03-27 23:34:35.795612 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-03-27 23:34:35.798797 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:38.955356 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:38.956862 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:41.786521 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-03-27 23:34:41.84942 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:41.852726 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:34:41.854686 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-03-27 23:34:41.856904 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:34:41.858734 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-03-27 23:34:41.867428 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-03-27 23:34:41.870579 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-03-27 23:34:41.873611 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:34:41.878622 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:34:41.883136 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-03-27 23:34:43.669107 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-03-27 23:34:44.867568 INFO::preprocessReads.R/preprocessReads: done
2024-03-27 23:34:44.980651 INFO::alignReads.R/alignReads: starting alignment...
2024-03-27 23:34:44.986259 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:47.929793 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:47.931661 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1206:17367:135118" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1304:1838:53573" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2303:2956:116587" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "M" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1206:20028:108227" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1207:19518:143960" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:2207:4065:173048" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:34:52.450241 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.075 minutes
2024-03-27 23:34:52.453707 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:52.455693 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-03-27 23:34:52.50381 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:34:52.512598 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-03-27 23:34:52.520625 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-03-27 23:34:52.52362 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:34:52.676934 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-03-27 23:34:52.723864 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:34:52.725009 INFO::alignReads.R/alignReads: done
2024-03-27 23:34:52.835772 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-03-27 23:34:52.856624 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:56.330136 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:56.332003 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:58.820986 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2024-03-27 23:34:58.823411 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:58.825236 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-03-27 23:34:58.83521 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-03-27 23:34:58.844134 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-03-27 23:34:58.850417 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-03-27 23:34:58.854253 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-03-27 23:34:58.858024 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-03-27 23:34:58.861968 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-03-27 23:34:58.868092 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-03-27 23:34:58.871859 INFO::countGenomicFeatures.R/mergeCounts: done
2024-03-27 23:34:58.875328 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-03-27 23:34:58.877086 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-03-27 23:34:59.093825 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-03-27 23:34:59.094837 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-03-27 23:34:59.188995 INFO::coverage.R/calculateCoverage: starting...
2024-03-27 23:34:59.193707 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:35:02.101987 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:35:02.103786 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-03-27 23:35:04.401454 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.038 minutes
2024-03-27 23:35:04.403688 DEBUG::tools.R/processChunks: done
2024-03-27 23:35:05.605649 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-03-27 23:35:05.607332 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-03-27 23:35:05.677648 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-03-27 23:35:05.679108 INFO::coverage.R/calculateCoverage: done
2024-03-27 23:35:05.680864 INFO::analyzeVariants/analyzeVariants: starting ...
2024-03-27 23:35:05.761857 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:35:16.527429 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:35:16.597264 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:35:16.612576 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:35:16.613875 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-03-27 23:35:16.616646 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-03-27 23:35:16.618016 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:35:16.619001 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:35:16.827984 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:35:16.922583 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-03-27 23:35:16.924814 INFO::analyzeVariants/analyzeVariants: done
2024-03-27 23:35:16.931918 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmp4jDZEH/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:35:17.14979 INFO::io.R/saveWithID: saving file= /tmp/Rtmp4jDZEH/test.calcTargetLengths.3a9cef2e9b3d9e/results/test_pe.summary_target_lengths.tab
 done successfully.



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



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



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



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

RUNIT TEST PROTOCOL -- Wed Mar 27 23:35:31 2024 
*********************************************** 
Number of test functions: 61 
Number of deactivated test functions: 10 
Number of errors: 0 
Number of failures: 0 

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



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (27.5 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (17.78 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.59 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (69.54 seconds)
test.wrap.callVariants: (4 checks) ... OK (10.28 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (19.92 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.81 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.14 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.48 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (29.44 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (24.43 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.67 seconds)
test.isSparse: (5 checks) ... OK (0.09 seconds)
test.mergeCoverage: (1 checks) ... OK (1.22 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.18 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.16 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.32 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.34 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.04 seconds)
test.isAdapter: (5 checks) ... OK (0.12 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.08 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.43 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.43 seconds)
test.getRRNAIds: (1 checks) ... OK (0.31 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.3 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.06 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.04 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.gatk.R 
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.14 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.15 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.26 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.14 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.14 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (1.57 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.1 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0 seconds)
test.writeAudit: (0 checks) ... OK (0.17 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (59.21 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.picard.R 
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (20.91 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (20.87 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (10.57 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.09 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.12 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.15 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (41.45 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.22 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (14.61 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.05 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.15 seconds) 

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

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

CHECK results for HTSeqGenie on nebbiolo1

Summary

Command output

Installation output

Tests output

Example timings