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

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo2	Linux (Ubuntu 22.04.3 LTS)	x86_64	4.4.0 RC (2024-04-16 r86468) -- "Puppy Cup"	4685
lconway	macOS 12.7.1 Monterey	x86_64	4.4.1 RC (2024-06-06 r86719) -- "Race for Your Life"	4400
Click on any hostname to see more info about the system (e.g. compilers) () as reported by 'uname -p', except on Windows and Mac OS X*

CHECK results for HTSeqGenie on nebbiolo2

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

raw results

Summary

Package: HTSeqGenie

Version: 4.35.0

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

StartedAt: 2024-06-17 00:00:44 -0400 (Mon, 17 Jun 2024)

EndedAt: 2024-06-17 00:14:21 -0400 (Mon, 17 Jun 2024)

EllapsedTime: 816.5 seconds

RetCode: 0

Status: OK

CheckDir: HTSeqGenie.Rcheck

Warnings: 0

Command output

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


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

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

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

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

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

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

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

Installation output

HTSeqGenie.Rcheck/00install.out

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


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

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.4.0 RC (2024-04-16 r86468) -- "Puppy Cup"
Copyright (C) 2024 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu

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

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

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

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

Attaching package: 'BiocGenerics'

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

    IQR, mad, sd, var, xtabs

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

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

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

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

    findMatches

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

    I, expand.grid, unname

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

Attaching package: 'Biostrings'

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

    strsplit

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

Attaching package: 'MatrixGenerics'

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

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

Loading required package: Biobase
Welcome to Bioconductor

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


Attaching package: 'Biobase'

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

    rowMedians

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

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

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

    tabulate

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


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:06:35.746684 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-17 00:06:35.755454 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:06:35.759037 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-17 00:06:35.761275 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:06:38.702514 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:06:38.703923 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/chunks/chunk_000001/logs/progress.log
2024-06-17 00:06:41.421039 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-06-17 00:06:41.422414 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/chunks/chunk_000002/logs/progress.log
2024-06-17 00:06:44.17216 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-06-17 00:06:44.174257 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/chunks/chunk_000003/logs/progress.log
2024-06-17 00:06:46.911596 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-06-17 00:06:46.945812 DEBUG::tools.R/processChunks: done
2024-06-17 00:06:46.94974 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:06:46.951966 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/results/test_pe.adapter_contaminated_1.RData
2024-06-17 00:06:46.954706 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-17 00:06:46.956271 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/results/test_pe.adapter_contaminated_2.RData
2024-06-17 00:06:46.965366 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-06-17 00:06:46.967597 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/results/test_pe.summary_preprocess.tab
2024-06-17 00:06:46.970923 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/bams/processed.aligner_input_1.fastq ...
2024-06-17 00:06:46.974783 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/bams/processed.aligner_input_2.fastq ...
2024-06-17 00:06:46.977876 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/reports/shortReadReport_1 ...
2024-06-17 00:06:48.310122 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/reports/shortReadReport_2 ...
2024-06-17 00:06:49.350582 INFO::preprocessReads.R/preprocessReads: done
2024-06-17 00:06:49.43857 INFO::alignReads.R/alignReads: starting alignment...
2024-06-17 00:06:49.444693 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:06:52.199525 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:06:52.201283 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/chunks/chunk_000001/logs/progress.log
2024-06-17 00:06:55.016778 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-06-17 00:06:55.018426 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/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-06-17 00:06:57.636974 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-06-17 00:06:57.638576 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/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-06-17 00:07:00.249268 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-06-17 00:07:00.253311 DEBUG::tools.R/processChunks: done
2024-06-17 00:07:00.255648 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-06-17 00:07:00.484731 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-17 00:07:00.492831 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/results/test_pe.summary_alignment.tab
2024-06-17 00:07:00.499568 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/results/test_pe.summary_analyzed_bamstats.tab
2024-06-17 00:07:00.501196 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-17 00:07:00.746055 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.188d901132d4ec/results/test_pe.summary_target_lengths.tab
2024-06-17 00:07:00.792376 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-17 00:07:00.793345 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:07:00.995651 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-17 00:07:00.998863 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:07:01.060881 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-06-17 00:07:01.065481 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:07:01.068403 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-17 00:07:01.070289 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:07:03.564143 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:07:03.565523 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/chunks/chunk_000001/logs/progress.log
2024-06-17 00:07:06.28184 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-06-17 00:07:06.283261 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/chunks/chunk_000002/logs/progress.log
2024-06-17 00:07:08.951088 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-06-17 00:07:08.952483 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/chunks/chunk_000003/logs/progress.log
2024-06-17 00:07:11.665969 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-06-17 00:07:11.669609 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/chunks/chunk_000004/logs/progress.log
2024-06-17 00:07:14.345366 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2024-06-17 00:07:14.395903 DEBUG::tools.R/processChunks: done
2024-06-17 00:07:14.400754 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:07:14.404869 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/results/test_pe.adapter_contaminated_1.RData
2024-06-17 00:07:14.408072 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-17 00:07:14.409813 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/results/test_pe.adapter_contaminated_2.RData
2024-06-17 00:07:14.420044 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-06-17 00:07:14.422357 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/results/test_pe.summary_preprocess.tab
2024-06-17 00:07:14.425893 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/bams/processed.aligner_input_1.fastq ...
2024-06-17 00:07:14.431528 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/bams/processed.aligner_input_2.fastq ...
2024-06-17 00:07:14.434585 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/reports/shortReadReport_1 ...
2024-06-17 00:07:15.682865 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.alignReads.sparsechunks.188d9039a6b7f3/reports/shortReadReport_2 ...
2024-06-17 00:07:16.636466 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:07:16.840014 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-06-17 00:07:16.84499 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/RtmpE7bK7p/test.alignReadsOneSingleEnd.188d905b62ec23/bams/test.alignReads /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-06-17 00:07:17.059677 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-06-17 00:07:17.148333 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReadsOneSingleEnd.188d905b62ec23/results/test.alignReads.summary_alignment.tab
2024-06-17 00:07:17.191021 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.alignReadsOneSingleEnd.188d905b62ec23/results/test.alignReads.summary_analyzed_bamstats.tab
2024-06-17 00:07:17.192463 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.002 0 0.001
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/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:07:17.480562 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.genotype.188d90285dafb4/results/test_pe.coverage.RData
2024-06-17 00:07:17.482327 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpE7bK7p/test.genotype.188d90285dafb4/results/test_pe.coverage.bw
2024-06-17 00:07:17.591215 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.genotype.188d90285dafb4/results/test_pe.summary_coverage.tab
2024-06-17 00:07:17.592784 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:07:27.456539 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:07:27.535052 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:07:27.550793 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:07:27.552257 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.genotype.188d90285dafb4/results/test_pe.raw_variants.RData
2024-06-17 00:07:27.554587 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.genotype.188d90285dafb4/results/test_pe.filtered_variants.RData
2024-06-17 00:07:27.555899 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-17 00:07:27.557085 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-17 00:07:27.931234 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-17 00:07:27.932551 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-06-17 00:08:22.153585 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-17 00:08:22.54938 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-17 00:08:22.550269 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/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:08:22.936207 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:08:32.855727 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:08:32.932216 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:08:32.948569 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:08:32.949872 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.188d9052b430ca/results/test_pe.raw_variants.RData
2024-06-17 00:08:32.952153 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.188d9052b430ca/results/test_pe.filtered_variants.RData
2024-06-17 00:08:32.953448 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:08:33.096321 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:08:43.065233 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:08:43.120964 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:08:43.136716 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:08:43.13802 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.filters.188d901b2c9b67/results/test_pe.raw_variants.RData
2024-06-17 00:08:43.140372 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.filters.188d901b2c9b67/results/test_pe.filtered_variants.RData
2024-06-17 00:08:43.141593 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-17 00:08:43.142999 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:08:53.441169 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:08:53.477872 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:08:53.494609 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:08:53.495913 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.filters.188d901b2c9b67/results/test_pe.raw_variants.RData
2024-06-17 00:08:53.498351 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.filters.188d901b2c9b67/results/test_pe.filtered_variants.RData
2024-06-17 00:08:53.500271 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:08:53.72328 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:08:53.724679 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-06-17 00:08:56.497445 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:08:56.563525 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:08:56.578868 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:08:56.580214 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.which.188d9071bcbc4c/results/test_pe.raw_variants.RData
2024-06-17 00:08:56.581834 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.wrap.callVariants.which.188d9071bcbc4c/results/test_pe.filtered_variants.RData
2024-06-17 00:08:56.583059 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:08:56.723058 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-17 00:08:56.724257 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:08:58.34931 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-17 00:08:58.536487 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-06-17 00:09:49.019588 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/mszylufi/merged/results/bla.coverage.RData
2024-06-17 00:09:49.022192 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpE7bK7p/mszylufi/merged/results/bla.coverage.bw
2024-06-17 00:09:49.100588 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/mszylufi/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-06-17 00:09:50.151383 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/mqrysuab/merged/results/bla.coverage.RData
2024-06-17 00:09:50.152819 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpE7bK7p/mqrysuab/merged/results/bla.coverage.bw
2024-06-17 00:09:50.163196 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/mqrysuab/merged/results/bla.summary_coverage.tab
 done successfully.



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



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



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



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



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



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



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



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



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



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



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



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:09:51.315093 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-06-17 00:09:51.31614 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpE7bK7p/test.detectRRNA.188d9025521b73/bams/rRNA_contam/input1.fastq
2024-06-17 00:09:51.319252 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/RtmpE7bK7p/test.detectRRNA.188d9025521b73/bams/rRNA_contam/test_se /tmp/RtmpE7bK7p/test.detectRRNA.188d9025521b73/bams/rRNA_contam/input1.fastq 2>&1
2024-06-17 00:09:51.444452 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-06-17 00:09:51.445376 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:09:51.578437 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-06-17 00:09:51.579312 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpE7bK7p/test.detectRRNA.paired_end.188d9069ee0da2/bams/rRNA_contam/input1.fastq
2024-06-17 00:09:51.580665 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpE7bK7p/test.detectRRNA.paired_end.188d9069ee0da2/bams/rRNA_contam/input2.fastq
2024-06-17 00:09:51.58262 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/RtmpE7bK7p/test.detectRRNA.paired_end.188d9069ee0da2/bams/rRNA_contam/test_pe /tmp/RtmpE7bK7p/test.detectRRNA.paired_end.188d9069ee0da2/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpE7bK7p/test.detectRRNA.paired_end.188d9069ee0da2/bams/rRNA_contam/input2.fastq 2>&1
2024-06-17 00:09:51.800616 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-06-17 00:09:51.801567 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-06-17 00:09:51.819259 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/RtmpE7bK7p/test_get_rRNA_idsedyvxfig/test_pe /tmp/RtmpE7bK7p/test_get_rRNA_idsedyvxfig/1.fastq -a paired /tmp/RtmpE7bK7p/test_get_rRNA_idsedyvxfig/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-06-17 00:09:52.055991 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/RtmpE7bK7p/test_get_rRNAIds_randomvidkbjsq/test_pe /tmp/RtmpE7bK7p/test_get_rRNAIds_randomvidkbjsq/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-06-17 00:09:52.284204 INFO::filterQuality.R/filterQuality: filterByLength...
2024-06-17 00:09:52.286391 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-06-17 00:09:52.287775 INFO::filterQuality.R/filterByLength: done
2024-06-17 00:09:52.345071 INFO::filterQuality.R/filterQuality: filterByLength...
2024-06-17 00:09:52.345953 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-06-17 00:09:52.346723 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-06-17 00:09:52.393627 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-17 00:09:52.402132 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-06-17 00:09:52.403143 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-17 00:09:52.407315 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-06-17 00:09:52.408248 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-17 00:09:52.412572 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-06-17 00:09:52.413502 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-17 00:09:52.417775 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



Executing test function test.realignIndelsGATK  ... Timing stopped at: 0.001 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/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:09:52.688077 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:09:52.690212 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:09:53.462829 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:09:53.53156 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-06-17 00:09:53.533851 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:09:53.535899 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:09:53.739321 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:09:53.783864 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-06-17 00:09:53.786156 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:09:53.788166 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



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



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



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:09:54.452338 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-17 00:09:54.458062 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:09:54.461471 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-17 00:09:54.463721 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:09:57.09471 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:09:57.096079 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000001/logs/progress.log
2024-06-17 00:09:59.746955 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-06-17 00:09:59.748425 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000002/logs/progress.log
2024-06-17 00:10:02.332563 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-06-17 00:10:02.334083 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000003/logs/progress.log
2024-06-17 00:10:04.886439 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-06-17 00:10:04.922507 DEBUG::tools.R/processChunks: done
2024-06-17 00:10:04.925175 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:10:04.926796 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.adapter_contaminated_1.RData
2024-06-17 00:10:04.928859 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-17 00:10:04.930391 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.adapter_contaminated_2.RData
2024-06-17 00:10:04.938424 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-06-17 00:10:04.940123 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.summary_preprocess.tab
2024-06-17 00:10:04.942437 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/bams/processed.aligner_input_1.fastq ...
2024-06-17 00:10:04.946643 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/bams/processed.aligner_input_2.fastq ...
2024-06-17 00:10:04.950377 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/reports/shortReadReport_1 ...
2024-06-17 00:10:06.200325 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/reports/shortReadReport_2 ...
2024-06-17 00:10:07.185056 INFO::preprocessReads.R/preprocessReads: done
2024-06-17 00:10:07.257119 INFO::alignReads.R/alignReads: starting alignment...
2024-06-17 00:10:07.261163 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:10:10.212287 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:10:10.214193 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000001/logs/progress.log
2024-06-17 00:10:12.725806 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-06-17 00:10:12.727808 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/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-06-17 00:10:15.331516 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-06-17 00:10:15.333169 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/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-06-17 00:10:17.896232 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-06-17 00:10:17.899395 DEBUG::tools.R/processChunks: done
2024-06-17 00:10:17.90127 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-06-17 00:10:18.097874 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-17 00:10:18.104729 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.summary_alignment.tab
2024-06-17 00:10:18.110645 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.summary_analyzed_bamstats.tab
2024-06-17 00:10:18.11226 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-17 00:10:18.354275 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.summary_target_lengths.tab
2024-06-17 00:10:18.399566 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-17 00:10:18.40055 INFO::alignReads.R/alignReads: done
2024-06-17 00:10:18.486711 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-06-17 00:10:18.505073 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:10:21.174842 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:10:21.17649 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000001/logs/progress.log
2024-06-17 00:10:23.639815 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2024-06-17 00:10:23.641517 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000002/logs/progress.log
2024-06-17 00:10:26.142171 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-06-17 00:10:26.145051 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000003/logs/progress.log
2024-06-17 00:10:28.579855 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2024-06-17 00:10:28.582913 DEBUG::tools.R/processChunks: done
2024-06-17 00:10:28.585124 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-06-17 00:10:28.603556 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.counts_exon.tab
2024-06-17 00:10:28.619952 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.counts_exon_disjoint.tab
2024-06-17 00:10:28.630251 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.counts_gene.tab
2024-06-17 00:10:28.637184 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.counts_gene_coding.tab
2024-06-17 00:10:28.642982 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.counts_gene_exonic.tab
2024-06-17 00:10:28.648803 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.counts_intergenic.tab
2024-06-17 00:10:28.658544 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.counts_intron.tab
2024-06-17 00:10:28.662407 INFO::countGenomicFeatures.R/mergeCounts: done
2024-06-17 00:10:28.668198 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.summary_counts.tab
2024-06-17 00:10:28.669924 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-06-17 00:10:28.959886 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-06-17 00:10:28.960891 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-06-17 00:10:29.037999 INFO::coverage.R/calculateCoverage: starting...
2024-06-17 00:10:29.042518 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:10:31.689769 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:10:31.6914 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000001/logs/progress.log
2024-06-17 00:10:33.839935 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-06-17 00:10:33.841805 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000002/logs/progress.log
2024-06-17 00:10:35.997331 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-06-17 00:10:35.998974 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/chunks/chunk_000003/logs/progress.log
2024-06-17 00:10:38.169745 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2024-06-17 00:10:38.172927 DEBUG::tools.R/processChunks: done
2024-06-17 00:10:39.360125 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.coverage.RData
2024-06-17 00:10:39.36145 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.coverage.bw
2024-06-17 00:10:39.372021 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.summary_coverage.tab
2024-06-17 00:10:39.373189 INFO::coverage.R/calculateCoverage: done
2024-06-17 00:10:39.374954 INFO::analyzeVariants/analyzeVariants: starting ...
2024-06-17 00:10:39.480534 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:10:42.179572 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:10:42.24508 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:10:42.26023 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:10:42.261504 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.raw_variants.RData
2024-06-17 00:10:42.262914 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.filtered_variants.RData
2024-06-17 00:10:42.264063 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-17 00:10:42.264974 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-17 00:10:42.460095 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-17 00:10:42.548915 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/results/test_pe.summary_variants.tab
2024-06-17 00:10:42.550723 INFO::analyzeVariants/analyzeVariants: done
2024-06-17 00:10:42.554487 INFO::Pipeline run successful.
2024-06-17 00:10:42.732098 INFO::mergeLanes.R/doMergeLanes: starting...
2024-06-17 00:10:42.736551 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:10:42.738599 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.adapter_contaminated_1.RData
2024-06-17 00:10:42.741426 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-17 00:10:42.74325 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.adapter_contaminated_2.RData
2024-06-17 00:10:42.754204 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-06-17 00:10:42.756321 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.summary_preprocess.tab
2024-06-17 00:10:42.758343 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-06-17 00:10:42.984296 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-17 00:10:42.991015 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.summary_alignment.tab
2024-06-17 00:10:42.998303 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.summary_analyzed_bamstats.tab
2024-06-17 00:10:43.000311 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-17 00:10:43.238553 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.summary_target_lengths.tab
2024-06-17 00:10:43.289406 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-17 00:10:43.322702 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-06-17 00:10:43.342627 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.counts_exon.tab
2024-06-17 00:10:43.355129 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.counts_exon_disjoint.tab
2024-06-17 00:10:43.362351 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.counts_gene.tab
2024-06-17 00:10:43.36754 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.counts_gene_coding.tab
2024-06-17 00:10:43.372744 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.counts_gene_exonic.tab
2024-06-17 00:10:43.378032 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.counts_intergenic.tab
2024-06-17 00:10:43.388992 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.counts_intron.tab
2024-06-17 00:10:43.392355 INFO::countGenomicFeatures.R/mergeCounts: done
2024-06-17 00:10:43.398259 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.summary_counts.tab
2024-06-17 00:10:43.399946 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-06-17 00:10:43.610731 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-06-17 00:10:45.38615 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.coverage.RData
2024-06-17 00:10:45.388988 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.coverage.bw
2024-06-17 00:10:45.399873 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.summary_coverage.tab
2024-06-17 00:10:45.434321 INFO::analyzeVariants/analyzeVariants: starting ...
2024-06-17 00:10:45.50356 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:10:48.230762 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:10:48.295058 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:10:48.30964 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:10:48.310873 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.raw_variants.RData
2024-06-17 00:10:48.312306 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.filtered_variants.RData
2024-06-17 00:10:48.31348 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-17 00:10:48.314386 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-17 00:10:48.509987 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-17 00:10:48.600819 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.mergeLanes.188d90243810b4/merged/results/merged.summary_variants.tab
2024-06-17 00:10:48.603007 INFO::analyzeVariants/analyzeVariants: done
2024-06-17 00:10:48.606382 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:10:48.862432 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-17 00:10:48.880621 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:10:48.900081 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-17 00:10:48.90262 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:10:51.654977 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:10:51.656336 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/chunks/chunk_000001/logs/progress.log
2024-06-17 00:10:54.266318 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-06-17 00:10:54.306018 DEBUG::tools.R/processChunks: done
2024-06-17 00:10:54.308262 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:10:54.309813 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/results/test_pe.adapter_contaminated_1.RData
2024-06-17 00:10:54.311491 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-17 00:10:54.312916 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/results/test_pe.adapter_contaminated_2.RData
2024-06-17 00:10:54.319314 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-06-17 00:10:54.321098 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/results/test_pe.summary_preprocess.tab
2024-06-17 00:10:54.322985 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/bams/processed.aligner_input_1.fastq ...
2024-06-17 00:10:54.3262 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/bams/processed.aligner_input_2.fastq ...
2024-06-17 00:10:54.329633 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/reports/shortReadReport_1 ...
2024-06-17 00:10:55.581538 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.preprocessReads.188d901ecc01a7/reports/shortReadReport_2 ...
2024-06-17 00:10:56.55545 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:10:56.778999 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-17 00:10:56.784377 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:10:56.787659 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-17 00:10:56.789821 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:10:59.529912 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:10:59.531306 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/chunks/chunk_000001/logs/progress.log
2024-06-17 00:11:02.117846 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-06-17 00:11:02.119938 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/chunks/chunk_000002/logs/progress.log
2024-06-17 00:11:04.719713 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-06-17 00:11:04.7214 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/chunks/chunk_000003/logs/progress.log
2024-06-17 00:11:07.2913 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-06-17 00:11:07.325611 DEBUG::tools.R/processChunks: done
2024-06-17 00:11:07.328154 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:11:07.329757 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/results/test_pe.adapter_contaminated_1.RData
2024-06-17 00:11:07.331714 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-17 00:11:07.33321 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/results/test_pe.adapter_contaminated_2.RData
2024-06-17 00:11:07.340765 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-06-17 00:11:07.342363 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/results/test_pe.summary_preprocess.tab
2024-06-17 00:11:07.344577 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/bams/processed.aligner_input_1.fastq ...
2024-06-17 00:11:07.348017 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/bams/processed.aligner_input_2.fastq ...
2024-06-17 00:11:07.350842 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/reports/shortReadReport_1 ...
2024-06-17 00:11:08.605887 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.preprocessReads.minichunks.188d902bb147dd/reports/shortReadReport_2 ...
2024-06-17 00:11:09.583182 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:11:09.815526 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-17 00:11:09.833037 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-17 00:11:09.835551 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:11:12.590498 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:11:12.591855 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpE7bK7p/test.preprocessReads_single_end.188d907e4b6f78/chunks/chunk_000001/logs/progress.log
2024-06-17 00:11:14.978203 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-06-17 00:11:14.988345 DEBUG::tools.R/processChunks: done
2024-06-17 00:11:14.990878 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:11:14.992497 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads_single_end.188d907e4b6f78/results/test_se.adapter_contaminated_1.RData
2024-06-17 00:11:14.999671 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-06-17 00:11:15.001493 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.preprocessReads_single_end.188d907e4b6f78/results/test_se.summary_preprocess.tab
2024-06-17 00:11:15.003448 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpE7bK7p/test.preprocessReads_single_end.188d907e4b6f78/bams/processed.aligner_input_1.fastq ...
2024-06-17 00:11:15.007396 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpE7bK7p/test.preprocessReads_single_end.188d907e4b6f78/reports/shortReadReport_1 ...
2024-06-17 00:11:16.271249 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



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



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



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



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



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



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:11:16.807422 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-17 00:11:16.824643 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-06-17 00:11:16.842916 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-06-17 00:11:16.845329 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:11:20.604753 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:11:20.607774 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-06-17 00:11:24.409548 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.063 minutes
2024-06-17 00:11:24.53303 DEBUG::tools.R/processChunks: done
2024-06-17 00:11:24.539933 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-17 00:11:24.544481 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-06-17 00:11:24.547575 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-17 00:11:24.550184 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-06-17 00:11:24.561287 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-06-17 00:11:24.564622 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-06-17 00:11:24.56827 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-06-17 00:11:24.597987 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-06-17 00:11:24.64102 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-06-17 00:11:29.171286 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-06-17 00:11:32.740193 INFO::preprocessReads.R/preprocessReads: done
2024-06-17 00:11:33.125421 INFO::alignReads.R/alignReads: starting alignment...
2024-06-17 00:11:33.135508 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:11:39.771919 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:11:39.774954 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-06-17 00:11:44.596357 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.08 minutes
2024-06-17 00:11:44.600194 DEBUG::tools.R/processChunks: done
2024-06-17 00:11:44.602598 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-06-17 00:11:44.649628 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-17 00:11:44.659297 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-06-17 00:11:44.667686 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-06-17 00:11:44.671114 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-17 00:11:44.923424 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-06-17 00:11:44.999509 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-17 00:11:45.001255 INFO::alignReads.R/alignReads: done
2024-06-17 00:11:45.173788 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-06-17 00:11:45.205322 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:11:50.316563 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:11:50.319625 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-06-17 00:11:53.266958 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2024-06-17 00:11:53.271378 DEBUG::tools.R/processChunks: done
2024-06-17 00:11:53.274556 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-06-17 00:11:53.290241 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-06-17 00:11:53.306327 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-06-17 00:11:53.318538 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-06-17 00:11:53.325979 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-06-17 00:11:53.333842 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-06-17 00:11:53.340968 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-06-17 00:11:53.352787 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-06-17 00:11:53.361048 INFO::countGenomicFeatures.R/mergeCounts: done
2024-06-17 00:11:53.369401 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-06-17 00:11:53.372534 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-06-17 00:11:53.714363 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-06-17 00:11:53.715966 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-06-17 00:11:53.918282 INFO::coverage.R/calculateCoverage: starting...
2024-06-17 00:11:53.92587 DEBUG::tools.R/processChunks: starting...
2024-06-17 00:11:58.653688 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-17 00:11:58.656986 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-06-17 00:12:01.110497 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2024-06-17 00:12:01.116086 DEBUG::tools.R/processChunks: done
2024-06-17 00:12:02.827471 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-06-17 00:12:02.829132 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-06-17 00:12:02.913178 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-06-17 00:12:02.914456 INFO::coverage.R/calculateCoverage: done
2024-06-17 00:12:02.915819 INFO::analyzeVariants/analyzeVariants: starting ...
2024-06-17 00:12:03.039866 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-17 00:12:13.755748 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-17 00:12:13.829628 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-17 00:12:13.845686 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-17 00:12:13.847086 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-06-17 00:12:13.850225 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-06-17 00:12:13.851613 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-17 00:12:13.852601 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-17 00:12:14.069721 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-17 00:12:14.161764 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-06-17 00:12:14.163553 INFO::analyzeVariants/analyzeVariants: done
2024-06-17 00:12:14.168265 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpE7bK7p/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-17 00:12:14.372997 INFO::io.R/saveWithID: saving file= /tmp/RtmpE7bK7p/test.calcTargetLengths.188d9062a1fca2/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 -- Mon Jun 17 00:12:29 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.20-bioc/R/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (26.38 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (15.84 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.55 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (65.62 seconds)
test.wrap.callVariants: (4 checks) ... OK (10.13 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (20.55 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (3.08 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.14 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (1.9 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (25.51 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (22.84 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.58 seconds)
test.isSparse: (5 checks) ... OK (0.09 seconds)
test.mergeCoverage: (1 checks) ... OK (1.46 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.08 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.13 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.3 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.33 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.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.03 seconds)
test.isAdapter: (5 checks) ... OK (0.11 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.07 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.26 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.36 seconds)
test.getRRNAIds: (1 checks) ... OK (0.23 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.24 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.07 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.04 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-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.20-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.31 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.14 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.16 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.52 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.13 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0 seconds)
test.writeAudit: (0 checks) ... OK (0.15 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (54.48 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-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.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (7.92 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (13.03 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (6.69 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.07 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.08 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-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.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (57.56 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.2 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (14.67 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.05 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.14 seconds) 

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

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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