Back to Multiple platform build/check report for BioC 3.18:   simplified   long
ABCDEFG[H]IJKLMNOPQRSTUVWXYZ

This page was generated on 2024-03-29 11:36:02 -0400 (Fri, 29 Mar 2024).

HostnameOSArch (*)R versionInstalled pkgs
nebbiolo2Linux (Ubuntu 22.04.3 LTS)x86_644.3.3 (2024-02-29) -- "Angel Food Cake" 4669
palomino4Windows Server 2022 Datacenterx644.3.3 (2024-02-29 ucrt) -- "Angel Food Cake" 4404
merida1macOS 12.7.1 Montereyx86_644.3.3 (2024-02-29) -- "Angel Food Cake" 4427
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 976/2266HostnameOS / ArchINSTALLBUILDCHECKBUILD BIN
HTSeqGenie 4.32.0  (landing page)
Jens Reeder
Snapshot Date: 2024-03-27 14:05:05 -0400 (Wed, 27 Mar 2024)
git_url: https://git.bioconductor.org/packages/HTSeqGenie
git_branch: RELEASE_3_18
git_last_commit: 9a84f3d
git_last_commit_date: 2023-10-24 09:51:39 -0400 (Tue, 24 Oct 2023)
nebbiolo2Linux (Ubuntu 22.04.3 LTS) / x86_64  OK    OK    OK  UNNEEDED, same version is already published
palomino4Windows Server 2022 Datacenter / x64... NOT SUPPORTED ...
merida1macOS 12.7.1 Monterey / x86_64... NOT SUPPORTED ...
kjohnson1macOS 13.6.1 Ventura / arm64see weekly results here

CHECK results for HTSeqGenie on nebbiolo2


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

raw results


Summary

Package: HTSeqGenie
Version: 4.32.0
Command: /home/biocbuild/bbs-3.18-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.18-bioc/R/site-library --timings HTSeqGenie_4.32.0.tar.gz
StartedAt: 2024-03-27 23:23:21 -0400 (Wed, 27 Mar 2024)
EndedAt: 2024-03-27 23:38:46 -0400 (Wed, 27 Mar 2024)
EllapsedTime: 925.2 seconds
RetCode: 0
Status:   OK  
CheckDir: HTSeqGenie.Rcheck
Warnings: 0

Command output

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


* using log directory ‘/home/biocbuild/bbs-3.18-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.3.3 (2024-02-29)
* using platform: x86_64-pc-linux-gnu (64-bit)
* 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.32.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 R 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 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 ... OK
* 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 ... OK
* 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 in ‘inst/doc’ ... OK
* checking running R code from vignettes ...
  ‘HTSeqGenie.Rnw’... OK
 OK
* checking re-building of vignette outputs ... OK
* checking PDF version of manual ... OK
* DONE

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



Installation output

HTSeqGenie.Rcheck/00install.out

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


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

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.3.3 (2024-02-29) -- "Angel Food Cake"
Copyright (C) 2024 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu (64-bit)

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, sort, 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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:29:19.371627 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:29:19.380113 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:29:19.38359 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:29:19.385764 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:29:22.256223 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:29:22.257587 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/chunks/chunk_000001/logs/progress.log
2024-03-27 23:29:25.032008 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:25.033581 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/chunks/chunk_000002/logs/progress.log
2024-03-27 23:29:27.785631 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:27.786984 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/chunks/chunk_000003/logs/progress.log
2024-03-27 23:29:30.528371 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:30.562715 DEBUG::tools.R/processChunks: done
2024-03-27 23:29:30.566838 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:29:30.569096 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:29:30.571876 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:29:30.573506 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:29:30.58265 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:30.584862 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/results/test_pe.summary_preprocess.tab
2024-03-27 23:29:30.588155 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:29:30.592978 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:29:30.595937 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/reports/shortReadReport_1 ...
2024-03-27 23:29:31.908845 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/reports/shortReadReport_2 ...
2024-03-27 23:29:34.111052 INFO::preprocessReads.R/preprocessReads: done
2024-03-27 23:29:34.160248 INFO::alignReads.R/alignReads: starting alignment...
2024-03-27 23:29:34.167813 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:29:37.312635 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:29:37.314349 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/chunks/chunk_000001/logs/progress.log
2024-03-27 23:29:40.158746 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-03-27 23:29:40.161822 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:29:42.807286 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-03-27 23:29:42.809925 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/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:45.504058 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-03-27 23:29:45.507617 DEBUG::tools.R/processChunks: done
2024-03-27 23:29:45.509677 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:29:45.765532 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:29:45.774878 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/results/test_pe.summary_alignment.tab
2024-03-27 23:29:45.782653 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/results/test_pe.summary_analyzed_bamstats.tab
2024-03-27 23:29:45.7846 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:29:46.045469 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.25365e7e56d340/results/test_pe.summary_target_lengths.tab
2024-03-27 23:29:46.094169 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:29:46.095296 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:29:46.342078 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:29:46.346038 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:29:46.434938 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-03-27 23:29:46.440125 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:29:46.443285 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:29:46.445441 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:29:49.34144 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:29:49.342882 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/chunks/chunk_000001/logs/progress.log
2024-03-27 23:29:52.104263 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:52.105733 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/chunks/chunk_000002/logs/progress.log
2024-03-27 23:29:54.845507 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-03-27 23:29:54.847652 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/chunks/chunk_000003/logs/progress.log
2024-03-27 23:29:57.643424 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.047 minutes
2024-03-27 23:29:57.645442 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/chunks/chunk_000004/logs/progress.log
2024-03-27 23:30:00.311662 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2024-03-27 23:30:00.339352 DEBUG::tools.R/processChunks: done
2024-03-27 23:30:00.342609 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:30:00.344806 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:30:00.347625 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:30:00.349295 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:30:00.359676 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:30:00.361918 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/results/test_pe.summary_preprocess.tab
2024-03-27 23:30:00.365614 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:30:00.369528 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:30:00.372437 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/reports/shortReadReport_1 ...
2024-03-27 23:30:01.615119 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.alignReads.sparsechunks.25365e6871104a/reports/shortReadReport_2 ...
2024-03-27 23:30:03.641819 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:30:03.812151 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-03-27 23:30:03.816488 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/Rtmps9v8xV/test.alignReadsOneSingleEnd.25365e1dd749e8/bams/test.alignReads /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-03-27 23:30:04.009229 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-03-27 23:30:04.103382 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReadsOneSingleEnd.25365e1dd749e8/results/test.alignReads.summary_alignment.tab
2024-03-27 23:30:04.150995 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.alignReadsOneSingleEnd.25365e1dd749e8/results/test.alignReads.summary_analyzed_bamstats.tab
2024-03-27 23:30:04.152625 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:30:04.468386 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.genotype.25365e8c1737b/results/test_pe.coverage.RData
2024-03-27 23:30:04.470335 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmps9v8xV/test.genotype.25365e8c1737b/results/test_pe.coverage.bw
2024-03-27 23:30:04.590797 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.genotype.25365e8c1737b/results/test_pe.summary_coverage.tab
2024-03-27 23:30:04.59258 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:30:14.593301 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:30:14.671801 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:30:14.688046 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:30:14.689683 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.genotype.25365e8c1737b/results/test_pe.raw_variants.RData
2024-03-27 23:30:14.692147 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.genotype.25365e8c1737b/results/test_pe.filtered_variants.RData
2024-03-27 23:30:14.693397 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:30:14.694532 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:30:15.083411 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:30:15.084473 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-03-27 23:30:58.150009 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:30:58.564128 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:30:58.564996 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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:30:58.955252 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:07.906601 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:07.9656 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:07.978706 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:07.979782 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.25365e35f74379/results/test_pe.raw_variants.RData
2024-03-27 23:31:07.981792 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.25365e35f74379/results/test_pe.filtered_variants.RData
2024-03-27 23:31:07.982858 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:08.105952 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:17.046572 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:17.093091 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:17.106538 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:17.107681 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.filters.25365e7e8af894/results/test_pe.raw_variants.RData
2024-03-27 23:31:17.109772 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.filters.25365e7e8af894/results/test_pe.filtered_variants.RData
2024-03-27 23:31:17.110819 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:31:17.11192 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:25.875717 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:25.907057 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:25.921335 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:25.922514 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.filters.25365e7e8af894/results/test_pe.raw_variants.RData
2024-03-27 23:31:25.924734 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.filters.25365e7e8af894/results/test_pe.filtered_variants.RData
2024-03-27 23:31:25.926543 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:26.07008 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:31:26.071367 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-03-27 23:31:28.083324 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:31:28.143985 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:31:28.157462 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:31:28.158638 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.which.25365e13dc7555/results/test_pe.raw_variants.RData
2024-03-27 23:31:28.159997 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.wrap.callVariants.which.25365e13dc7555/results/test_pe.filtered_variants.RData
2024-03-27 23:31:28.161043 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



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



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:31:28.450046 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:31:28.645398 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:21.372434 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/pawernvz/merged/results/bla.coverage.RData
2024-03-27 23:32:21.374898 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmps9v8xV/pawernvz/merged/results/bla.coverage.bw
2024-03-27 23:32:21.454779 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/pawernvz/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-03-27 23:32:22.552517 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/hcwfuzsd/merged/results/bla.coverage.RData
2024-03-27 23:32:22.553902 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmps9v8xV/hcwfuzsd/merged/results/bla.coverage.bw
2024-03-27 23:32:22.564745 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/hcwfuzsd/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:23.751935 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-03-27 23:32:23.753007 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmps9v8xV/test.detectRRNA.25365e3cdd0aed/bams/rRNA_contam/input1.fastq
2024-03-27 23:32:23.756065 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/Rtmps9v8xV/test.detectRRNA.25365e3cdd0aed/bams/rRNA_contam/test_se /tmp/Rtmps9v8xV/test.detectRRNA.25365e3cdd0aed/bams/rRNA_contam/input1.fastq 2>&1
2024-03-27 23:32:23.893473 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-03-27 23:32:23.894457 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:24.035579 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-03-27 23:32:24.036492 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmps9v8xV/test.detectRRNA.paired_end.25365e39786004/bams/rRNA_contam/input1.fastq
2024-03-27 23:32:24.037889 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmps9v8xV/test.detectRRNA.paired_end.25365e39786004/bams/rRNA_contam/input2.fastq
2024-03-27 23:32:24.039953 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/Rtmps9v8xV/test.detectRRNA.paired_end.25365e39786004/bams/rRNA_contam/test_pe /tmp/Rtmps9v8xV/test.detectRRNA.paired_end.25365e39786004/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmps9v8xV/test.detectRRNA.paired_end.25365e39786004/bams/rRNA_contam/input2.fastq 2>&1
2024-03-27 23:32:24.266868 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-03-27 23:32:24.267849 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



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



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



Executing test function test.filterByLength  ... 2024-03-27 23:32:24.745755 INFO::filterQuality.R/filterQuality: filterByLength...
2024-03-27 23:32:24.747275 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-03-27 23:32:24.748153 INFO::filterQuality.R/filterByLength: done
2024-03-27 23:32:24.796566 INFO::filterQuality.R/filterQuality: filterByLength...
2024-03-27 23:32:24.797506 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-03-27 23:32:24.798343 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-03-27 23:32:24.846251 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:24.854786 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-03-27 23:32:24.855844 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:24.860192 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-03-27 23:32:24.861181 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:24.865458 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-03-27 23:32:24.866385 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-03-27 23:32:24.870529 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.001 0 0
Error in DEACTIVATED("checkGATKJar() test needs gatk.path option set") : 
  checkGATKJar() test needs gatk.path option set
 done successfully.



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:25.152533 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:25.154756 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:25.323651 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:25.408769 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-03-27 23:32:25.41154 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:25.413686 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:25.621096 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:25.758848 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:25.908548 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:25.968433 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-03-27 23:32:25.97094 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:25.973082 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:26.159424 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:26.197634 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-03-27 23:32:26.200084 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:26.202208 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-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/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:32:27.914205 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:32:27.920042 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:32:27.92372 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:32:27.926236 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:32:30.79429 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:32:30.795726 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000001/logs/progress.log
2024-03-27 23:32:33.348028 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-03-27 23:32:33.349291 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000002/logs/progress.log
2024-03-27 23:32:36.016291 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-03-27 23:32:36.018277 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000003/logs/progress.log
2024-03-27 23:32:38.70467 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-03-27 23:32:38.746507 DEBUG::tools.R/processChunks: done
2024-03-27 23:32:38.749445 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:32:38.751176 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:32:38.753266 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:32:38.754784 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:32:38.763914 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:38.765863 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.summary_preprocess.tab
2024-03-27 23:32:38.768584 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:32:38.772315 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:32:38.775578 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/reports/shortReadReport_1 ...
2024-03-27 23:32:40.063728 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/reports/shortReadReport_2 ...
2024-03-27 23:32:41.061789 INFO::preprocessReads.R/preprocessReads: done
2024-03-27 23:32:41.118413 INFO::alignReads.R/alignReads: starting alignment...
2024-03-27 23:32:41.123266 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:32:44.189796 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:32:44.191695 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000001/logs/progress.log
2024-03-27 23:32:46.764147 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-03-27 23:32:46.766356 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:32:49.341968 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-03-27 23:32:49.343858 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/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:32:51.90705 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-03-27 23:32:51.911029 DEBUG::tools.R/processChunks: done
2024-03-27 23:32:51.913454 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:32:52.110397 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:32:52.119081 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.summary_alignment.tab
2024-03-27 23:32:52.12638 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.summary_analyzed_bamstats.tab
2024-03-27 23:32:52.128364 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:32:52.358063 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.summary_target_lengths.tab
2024-03-27 23:32:52.406902 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:32:52.40806 INFO::alignReads.R/alignReads: done
2024-03-27 23:32:52.48438 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-03-27 23:32:52.502915 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:32:55.528585 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:32:55.530428 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000001/logs/progress.log
2024-03-27 23:32:58.051153 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-03-27 23:32:58.052932 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000002/logs/progress.log
2024-03-27 23:33:01.137464 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.051 minutes
2024-03-27 23:33:01.140694 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000003/logs/progress.log
2024-03-27 23:33:04.249906 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.052 minutes
2024-03-27 23:33:04.2547 DEBUG::tools.R/processChunks: done
2024-03-27 23:33:04.259406 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-03-27 23:33:04.304689 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.counts_exon.tab
2024-03-27 23:33:04.340494 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.counts_exon_disjoint.tab
2024-03-27 23:33:04.35709 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.counts_gene.tab
2024-03-27 23:33:04.368949 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.counts_gene_coding.tab
2024-03-27 23:33:04.381084 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.counts_gene_exonic.tab
2024-03-27 23:33:04.392714 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.counts_intergenic.tab
2024-03-27 23:33:04.411897 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.counts_intron.tab
2024-03-27 23:33:04.418681 INFO::countGenomicFeatures.R/mergeCounts: done
2024-03-27 23:33:04.43064 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.summary_counts.tab
2024-03-27 23:33:04.433786 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-03-27 23:33:05.077533 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-03-27 23:33:05.079314 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-03-27 23:33:05.478399 INFO::coverage.R/calculateCoverage: starting...
2024-03-27 23:33:05.485658 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:33:12.002373 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:33:12.006186 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000001/logs/progress.log
2024-03-27 23:33:14.485895 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2024-03-27 23:33:14.488934 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000002/logs/progress.log
2024-03-27 23:33:17.128042 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-03-27 23:33:17.13168 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/chunks/chunk_000003/logs/progress.log
2024-03-27 23:33:19.445387 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.039 minutes
2024-03-27 23:33:19.450228 DEBUG::tools.R/processChunks: done
2024-03-27 23:33:21.381769 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.coverage.RData
2024-03-27 23:33:21.38338 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.coverage.bw
2024-03-27 23:33:21.395039 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.summary_coverage.tab
2024-03-27 23:33:21.396365 INFO::coverage.R/calculateCoverage: done
2024-03-27 23:33:21.398622 INFO::analyzeVariants/analyzeVariants: starting ...
2024-03-27 23:33:21.489399 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:33:24.074522 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:33:24.148361 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:33:24.164018 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:33:24.165351 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.raw_variants.RData
2024-03-27 23:33:24.166913 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.filtered_variants.RData
2024-03-27 23:33:24.1681 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:33:24.169019 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:33:24.391496 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:33:24.489853 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/results/test_pe.summary_variants.tab
2024-03-27 23:33:24.492078 INFO::analyzeVariants/analyzeVariants: done
2024-03-27 23:33:24.496885 INFO::Pipeline run successful.
2024-03-27 23:33:24.769315 INFO::mergeLanes.R/doMergeLanes: starting...
2024-03-27 23:33:24.775369 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:33:24.778185 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.adapter_contaminated_1.RData
2024-03-27 23:33:24.781764 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:33:24.784134 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.adapter_contaminated_2.RData
2024-03-27 23:33:24.798875 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:24.801583 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.summary_preprocess.tab
2024-03-27 23:33:24.804307 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-03-27 23:33:25.114582 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:33:25.123025 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.summary_alignment.tab
2024-03-27 23:33:25.131749 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.summary_analyzed_bamstats.tab
2024-03-27 23:33:25.134033 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:33:25.407448 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.summary_target_lengths.tab
2024-03-27 23:33:25.462679 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:33:25.510458 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-03-27 23:33:25.534438 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.counts_exon.tab
2024-03-27 23:33:25.549256 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.counts_exon_disjoint.tab
2024-03-27 23:33:25.558648 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.counts_gene.tab
2024-03-27 23:33:25.565852 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.counts_gene_coding.tab
2024-03-27 23:33:25.572862 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.counts_gene_exonic.tab
2024-03-27 23:33:25.580014 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.counts_intergenic.tab
2024-03-27 23:33:25.59568 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.counts_intron.tab
2024-03-27 23:33:25.599667 INFO::countGenomicFeatures.R/mergeCounts: done
2024-03-27 23:33:25.607143 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.summary_counts.tab
2024-03-27 23:33:25.609353 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-03-27 23:33:25.841163 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-03-27 23:33:29.256108 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.coverage.RData
2024-03-27 23:33:29.262908 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.coverage.bw
2024-03-27 23:33:29.286722 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.summary_coverage.tab
2024-03-27 23:33:29.364793 INFO::analyzeVariants/analyzeVariants: starting ...
2024-03-27 23:33:29.52589 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:33:34.279853 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:33:34.423725 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:33:34.448682 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:33:34.450074 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.raw_variants.RData
2024-03-27 23:33:34.45168 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.filtered_variants.RData
2024-03-27 23:33:34.452854 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:33:34.453745 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:33:34.700365 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:33:34.815474 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.mergeLanes.25365e30312510/merged/results/merged.summary_variants.tab
2024-03-27 23:33:34.81762 INFO::analyzeVariants/analyzeVariants: done
2024-03-27 23:33:34.821839 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:33:35.257077 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:33:35.282869 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:33:35.308229 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:33:35.312378 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:33:41.775053 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:33:41.777856 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/chunks/chunk_000001/logs/progress.log
2024-03-27 23:33:44.844185 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2024-03-27 23:33:44.910265 DEBUG::tools.R/processChunks: done
2024-03-27 23:33:44.913934 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:33:44.916303 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:33:44.918968 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:33:44.921148 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:33:44.931222 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:44.934199 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/results/test_pe.summary_preprocess.tab
2024-03-27 23:33:44.937721 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:33:44.944778 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:33:44.951532 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/reports/shortReadReport_1 ...
2024-03-27 23:33:47.367853 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.preprocessReads.25365e2a0ba28f/reports/shortReadReport_2 ...
2024-03-27 23:33:50.285367 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:33:50.726697 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:33:50.735601 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:33:50.741326 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-03-27 23:33:50.745038 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:33:54.932138 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:33:54.93385 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/chunks/chunk_000001/logs/progress.log
2024-03-27 23:33:57.574154 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-03-27 23:33:57.575841 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/chunks/chunk_000002/logs/progress.log
2024-03-27 23:34:00.145374 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-03-27 23:34:00.146826 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/chunks/chunk_000003/logs/progress.log
2024-03-27 23:34:02.79422 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-03-27 23:34:02.842519 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:02.845757 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:34:02.847558 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/results/test_pe.adapter_contaminated_1.RData
2024-03-27 23:34:02.849786 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:34:02.851458 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/results/test_pe.adapter_contaminated_2.RData
2024-03-27 23:34:02.860751 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:02.862968 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/results/test_pe.summary_preprocess.tab
2024-03-27 23:34:02.865968 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:34:02.871163 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:34:02.875282 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/reports/shortReadReport_1 ...
2024-03-27 23:34:04.201452 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.preprocessReads.minichunks.25365ed646ff6/reports/shortReadReport_2 ...
2024-03-27 23:34:05.195458 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:34:05.463298 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:34:05.482518 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-03-27 23:34:05.485321 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:08.669446 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:08.670897 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmps9v8xV/test.preprocessReads_single_end.25365e29297a36/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:11.055844 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-03-27 23:34:11.090415 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:11.09335 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:34:11.095328 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads_single_end.25365e29297a36/results/test_se.adapter_contaminated_1.RData
2024-03-27 23:34:11.102304 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:11.104117 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.preprocessReads_single_end.25365e29297a36/results/test_se.summary_preprocess.tab
2024-03-27 23:34:11.106074 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmps9v8xV/test.preprocessReads_single_end.25365e29297a36/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:34:11.110448 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmps9v8xV/test.preprocessReads_single_end.25365e29297a36/reports/shortReadReport_1 ...
2024-03-27 23:34:12.368974 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.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:34:12.93298 INFO::preprocessReads.R/preprocessReads: starting...
2024-03-27 23:34:12.954183 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-03-27 23:34:12.973773 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-03-27 23:34:12.976201 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:15.871994 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:15.873454 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:18.742733 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2024-03-27 23:34:18.786842 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:18.79006 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-03-27 23:34:18.791733 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-03-27 23:34:18.793387 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-03-27 23:34:18.794665 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-03-27 23:34:18.801033 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:18.802705 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-03-27 23:34:18.804678 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-03-27 23:34:18.809121 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-03-27 23:34:18.813297 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-03-27 23:34:20.235845 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-03-27 23:34:21.423848 INFO::preprocessReads.R/preprocessReads: done
2024-03-27 23:34:21.489127 INFO::alignReads.R/alignReads: starting alignment...
2024-03-27 23:34:21.494806 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:25.245189 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:25.247267 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:29.686618 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.074 minutes
2024-03-27 23:34:29.689038 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:29.690685 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-03-27 23:34:29.723989 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-03-27 23:34:29.730744 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-03-27 23:34:29.736032 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-03-27 23:34:29.738066 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-03-27 23:34:29.895932 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-03-27 23:34:29.9439 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-03-27 23:34:29.94502 INFO::alignReads.R/alignReads: done
2024-03-27 23:34:30.023058 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-03-27 23:34:30.040901 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:32.928507 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:32.930209 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:35.388013 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2024-03-27 23:34:35.390172 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:35.39159 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-03-27 23:34:35.399496 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-03-27 23:34:35.407553 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-03-27 23:34:35.413534 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-03-27 23:34:35.417087 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-03-27 23:34:35.420554 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-03-27 23:34:35.423949 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-03-27 23:34:35.429135 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-03-27 23:34:35.433465 INFO::countGenomicFeatures.R/mergeCounts: done
2024-03-27 23:34:35.436723 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-03-27 23:34:35.438191 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-03-27 23:34:35.647891 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-03-27 23:34:35.648777 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-03-27 23:34:35.747499 INFO::coverage.R/calculateCoverage: starting...
2024-03-27 23:34:35.752058 DEBUG::tools.R/processChunks: starting...
2024-03-27 23:34:39.128644 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-03-27 23:34:39.130831 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-03-27 23:34:41.467432 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-03-27 23:34:41.470139 DEBUG::tools.R/processChunks: done
2024-03-27 23:34:42.976624 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-03-27 23:34:42.978289 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-03-27 23:34:43.059819 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-03-27 23:34:43.061213 INFO::coverage.R/calculateCoverage: done
2024-03-27 23:34:43.062679 INFO::analyzeVariants/analyzeVariants: starting ...
2024-03-27 23:34:43.13328 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-03-27 23:34:53.324081 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-03-27 23:34:53.386949 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-03-27 23:34:53.40096 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-03-27 23:34:53.402097 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-03-27 23:34:53.404732 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-03-27 23:34:53.405864 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-03-27 23:34:53.406702 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-03-27 23:34:53.596618 INFO::analyzeVariants.R/writeVCF: ...done
2024-03-27 23:34:53.67942 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-03-27 23:34:53.681273 INFO::analyzeVariants/analyzeVariants: done
2024-03-27 23:34:53.686262 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmps9v8xV/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-03-27 23:34:53.898961 INFO::io.R/saveWithID: saving file= /tmp/Rtmps9v8xV/test.calcTargetLengths.25365e3f291e86/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:07 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.18-bioc/R/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (28.18 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (17.54 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.5 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (54.67 seconds)
test.wrap.callVariants: (4 checks) ... OK (9.15 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (17.94 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.23 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.12 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.44 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (27.23 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (23.36 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.72 seconds)
test.isSparse: (5 checks) ... OK (0.09 seconds)
test.mergeCoverage: (1 checks) ... OK (1.32 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.13 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.15 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.3 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.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.03 seconds)
test.isAdapter: (5 checks) ... OK (0.12 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.08 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.28 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.37 seconds)
test.getRRNAIds: (1 checks) ... OK (0.24 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.23 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-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.18-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.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.17 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.3 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.15 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.15 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.49 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.12 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.18 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (68.27 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-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.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (15.42 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (14.9 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (7.17 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.08 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.08 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.13 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (40.96 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.21 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (13.52 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.18-bioc/R/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.06 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 
248.864  64.212 367.253 

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

nameusersystemelapsed
HTSeqGenie0.0010.0000.000
buildGenomicFeaturesFromTxDb000
runPipeline0.0000.0000.001