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

Hostname	OS	Arch (*)	R version	Installed pkgs
nebbiolo1	Linux (Ubuntu 22.04.3 LTS)	x86_64	4.4.0 (2024-04-24) -- "Puppy Cup"	4760
palomino3	Windows Server 2022 Datacenter	x64	4.4.0 (2024-04-24 ucrt) -- "Puppy Cup"	4494
merida1	macOS 12.7.4 Monterey	x86_64	4.4.0 (2024-04-24) -- "Puppy Cup"	4508
kjohnson1	macOS 13.6.6 Ventura	arm64	4.4.0 (2024-04-24) -- "Puppy Cup"	4466
Click on any hostname to see more info about the system (e.g. compilers) () as reported by 'uname -p', except on Windows and Mac OS X*

CHECK results for HTSeqGenie on nebbiolo1

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

raw results

Summary

Package: HTSeqGenie

Version: 4.34.0

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

StartedAt: 2024-06-24 00:12:07 -0400 (Mon, 24 Jun 2024)

EndedAt: 2024-06-24 00:25:47 -0400 (Mon, 24 Jun 2024)

EllapsedTime: 819.7 seconds

RetCode: 0

Status: OK

CheckDir: HTSeqGenie.Rcheck

Warnings: 0

Command output

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


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

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

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

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

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

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

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

Installation output

HTSeqGenie.Rcheck/00install.out

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


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

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.4.0 (2024-04-24) -- "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/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:17:46.063647 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-24 00:17:46.071393 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:17:46.074793 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-24 00:17:46.076784 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:17:48.673727 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:17:48.67513 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/chunks/chunk_000001/logs/progress.log
2024-06-24 00:17:51.369539 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-06-24 00:17:51.370898 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/chunks/chunk_000002/logs/progress.log
2024-06-24 00:17:54.071649 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-06-24 00:17:54.072951 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/chunks/chunk_000003/logs/progress.log
2024-06-24 00:17:56.749267 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-06-24 00:17:56.774962 DEBUG::tools.R/processChunks: done
2024-06-24 00:17:56.778719 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:17:56.78089 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/results/test_pe.adapter_contaminated_1.RData
2024-06-24 00:17:56.783443 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-24 00:17:56.784918 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/results/test_pe.adapter_contaminated_2.RData
2024-06-24 00:17:56.793289 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-24 00:17:56.795375 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/results/test_pe.summary_preprocess.tab
2024-06-24 00:17:56.798328 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/bams/processed.aligner_input_1.fastq ...
2024-06-24 00:17:56.802599 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/bams/processed.aligner_input_2.fastq ...
2024-06-24 00:17:56.805487 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/reports/shortReadReport_1 ...
2024-06-24 00:17:58.064257 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/reports/shortReadReport_2 ...
2024-06-24 00:17:59.068133 INFO::preprocessReads.R/preprocessReads: done
2024-06-24 00:17:59.143711 INFO::alignReads.R/alignReads: starting alignment...
2024-06-24 00:17:59.149178 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:18:01.682674 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:18:01.684323 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/chunks/chunk_000001/logs/progress.log
2024-06-24 00:18:04.439701 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-06-24 00:18:04.441375 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-06-24 00:18:07.069709 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-06-24 00:18:07.071782 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/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-24 00:18:09.688622 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-06-24 00:18:09.690942 DEBUG::tools.R/processChunks: done
2024-06-24 00:18:09.692303 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-06-24 00:18:09.897569 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-24 00:18:09.906172 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/results/test_pe.summary_alignment.tab
2024-06-24 00:18:09.913528 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/results/test_pe.summary_analyzed_bamstats.tab
2024-06-24 00:18:09.915326 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-24 00:18:10.167782 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.1bb82416ff0812/results/test_pe.summary_target_lengths.tab
2024-06-24 00:18:10.216103 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-24 00:18:10.217172 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:18:10.43106 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-24 00:18:10.435254 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:18:10.51851 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-06-24 00:18:10.524828 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:18:10.528591 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-24 00:18:10.531248 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:18:13.674638 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:18:13.677087 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/chunks/chunk_000001/logs/progress.log
2024-06-24 00:18:16.38027 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-06-24 00:18:16.381805 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/chunks/chunk_000002/logs/progress.log
2024-06-24 00:18:19.083158 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-06-24 00:18:19.084674 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/chunks/chunk_000003/logs/progress.log
2024-06-24 00:18:21.846114 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-06-24 00:18:21.847454 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/chunks/chunk_000004/logs/progress.log
2024-06-24 00:18:24.517758 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2024-06-24 00:18:24.551741 DEBUG::tools.R/processChunks: done
2024-06-24 00:18:24.555235 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:18:24.55757 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/results/test_pe.adapter_contaminated_1.RData
2024-06-24 00:18:24.560518 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-24 00:18:24.562197 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/results/test_pe.adapter_contaminated_2.RData
2024-06-24 00:18:24.572328 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-24 00:18:24.574467 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/results/test_pe.summary_preprocess.tab
2024-06-24 00:18:24.577997 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/bams/processed.aligner_input_1.fastq ...
2024-06-24 00:18:24.582804 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/bams/processed.aligner_input_2.fastq ...
2024-06-24 00:18:24.58671 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/reports/shortReadReport_1 ...
2024-06-24 00:18:25.857962 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.alignReads.sparsechunks.1bb8242603c02a/reports/shortReadReport_2 ...
2024-06-24 00:18:26.855015 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:18:27.012858 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-06-24 00:18:27.017453 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/RtmpurojSL/test.alignReadsOneSingleEnd.1bb824b774068/bams/test.alignReads /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-06-24 00:18:27.217612 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-06-24 00:18:27.307737 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReadsOneSingleEnd.1bb824b774068/results/test.alignReads.summary_alignment.tab
2024-06-24 00:18:27.348705 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.alignReadsOneSingleEnd.1bb824b774068/results/test.alignReads.summary_analyzed_bamstats.tab
2024-06-24 00:18:27.350404 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:18:27.639561 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.genotype.1bb82413d7968b/results/test_pe.coverage.RData
2024-06-24 00:18:27.641382 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpurojSL/test.genotype.1bb82413d7968b/results/test_pe.coverage.bw
2024-06-24 00:18:27.760964 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.genotype.1bb82413d7968b/results/test_pe.summary_coverage.tab
2024-06-24 00:18:27.762928 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:18:37.91706 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:18:37.997282 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:18:38.012966 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:18:38.01449 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.genotype.1bb82413d7968b/results/test_pe.raw_variants.RData
2024-06-24 00:18:38.016866 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.genotype.1bb82413d7968b/results/test_pe.filtered_variants.RData
2024-06-24 00:18:38.018173 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-24 00:18:38.019352 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-24 00:18:38.394654 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-24 00:18:38.395994 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-06-24 00:19:31.289548 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-24 00:19:31.694289 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-24 00:19:31.695255 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/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:19:32.099887 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:19:41.981297 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:19:42.055243 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:19:42.07134 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:19:42.072703 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.1bb824171e3e69/results/test_pe.raw_variants.RData
2024-06-24 00:19:42.075042 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.1bb824171e3e69/results/test_pe.filtered_variants.RData
2024-06-24 00:19:42.076314 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:19:42.214682 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:19:51.923271 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:19:51.977286 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:19:51.993587 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:19:51.995054 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.filters.1bb824447d90e9/results/test_pe.raw_variants.RData
2024-06-24 00:19:51.997528 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.filters.1bb824447d90e9/results/test_pe.filtered_variants.RData
2024-06-24 00:19:51.998884 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-24 00:19:52.000329 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:20:01.935338 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:20:01.97143 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:20:01.987325 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:20:01.988672 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.filters.1bb824447d90e9/results/test_pe.raw_variants.RData
2024-06-24 00:20:01.991189 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.filters.1bb824447d90e9/results/test_pe.filtered_variants.RData
2024-06-24 00:20:01.993173 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:20:02.217234 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:20:02.218654 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-06-24 00:20:04.856028 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:20:04.924559 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:20:04.940608 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:20:04.942006 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.which.1bb824145c47fe/results/test_pe.raw_variants.RData
2024-06-24 00:20:04.943639 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.wrap.callVariants.which.1bb824145c47fe/results/test_pe.filtered_variants.RData
2024-06-24 00:20:04.944852 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:20:05.078108 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-24 00:20:05.079294 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:20:06.498488 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-24 00:20:06.673934 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-24 00:20:56.944943 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/pojbhgxv/merged/results/bla.coverage.RData
2024-06-24 00:20:56.947595 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpurojSL/pojbhgxv/merged/results/bla.coverage.bw
2024-06-24 00:20:57.018644 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/pojbhgxv/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-06-24 00:20:58.105753 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/gzoeiqpr/merged/results/bla.coverage.RData
2024-06-24 00:20:58.107301 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpurojSL/gzoeiqpr/merged/results/bla.coverage.bw
2024-06-24 00:20:58.118425 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/gzoeiqpr/merged/results/bla.summary_coverage.tab
 done successfully.



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



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



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



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



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



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



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



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



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



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



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



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:20:59.335145 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-06-24 00:20:59.336284 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpurojSL/test.detectRRNA.1bb8245900af44/bams/rRNA_contam/input1.fastq
2024-06-24 00:20:59.339422 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/RtmpurojSL/test.detectRRNA.1bb8245900af44/bams/rRNA_contam/test_se /tmp/RtmpurojSL/test.detectRRNA.1bb8245900af44/bams/rRNA_contam/input1.fastq 2>&1
2024-06-24 00:20:59.595562 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-06-24 00:20:59.596496 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:20:59.741128 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-06-24 00:20:59.742079 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpurojSL/test.detectRRNA.paired_end.1bb82489c6b38/bams/rRNA_contam/input1.fastq
2024-06-24 00:20:59.743618 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpurojSL/test.detectRRNA.paired_end.1bb82489c6b38/bams/rRNA_contam/input2.fastq
2024-06-24 00:20:59.745628 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/RtmpurojSL/test.detectRRNA.paired_end.1bb82489c6b38/bams/rRNA_contam/test_pe /tmp/RtmpurojSL/test.detectRRNA.paired_end.1bb82489c6b38/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpurojSL/test.detectRRNA.paired_end.1bb82489c6b38/bams/rRNA_contam/input2.fastq 2>&1
2024-06-24 00:21:00.010801 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-06-24 00:21:00.011746 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-06-24 00:21:00.02934 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/RtmpurojSL/test_get_rRNA_idslcnxvfst/test_pe /tmp/RtmpurojSL/test_get_rRNA_idslcnxvfst/1.fastq -a paired /tmp/RtmpurojSL/test_get_rRNA_idslcnxvfst/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-06-24 00:21:00.30707 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/RtmpurojSL/test_get_rRNAIds_randomxksrnile/test_pe /tmp/RtmpurojSL/test_get_rRNAIds_randomxksrnile/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-06-24 00:21:00.522876 INFO::filterQuality.R/filterQuality: filterByLength...
2024-06-24 00:21:00.525119 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-06-24 00:21:00.526488 INFO::filterQuality.R/filterByLength: done
2024-06-24 00:21:00.601266 INFO::filterQuality.R/filterQuality: filterByLength...
2024-06-24 00:21:00.602763 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-06-24 00:21:00.604137 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-06-24 00:21:00.663327 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-24 00:21:00.672074 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-06-24 00:21:00.673133 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-24 00:21:00.677282 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-06-24 00:21:00.678204 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-24 00:21:00.682406 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-06-24 00:21:00.683322 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-06-24 00:21:00.687379 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:21:00.962066 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:21:00.96426 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:21:02.671643 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:21:02.733447 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-06-24 00:21:02.73587 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:21:02.737977 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:21:02.931046 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:21:02.976435 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-06-24 00:21:02.978736 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:21:02.980798 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



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



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



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:21:03.671227 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-24 00:21:03.676951 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:21:03.680412 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-24 00:21:03.682717 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:21:06.968202 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:21:06.9697 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000001/logs/progress.log
2024-06-24 00:21:09.656299 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-06-24 00:21:09.6579 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000002/logs/progress.log
2024-06-24 00:21:12.258082 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-06-24 00:21:12.260143 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000003/logs/progress.log
2024-06-24 00:21:14.842013 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-06-24 00:21:14.87851 DEBUG::tools.R/processChunks: done
2024-06-24 00:21:14.881283 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:21:14.882918 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.adapter_contaminated_1.RData
2024-06-24 00:21:14.884932 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-24 00:21:14.886459 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.adapter_contaminated_2.RData
2024-06-24 00:21:14.894053 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-24 00:21:14.895671 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.summary_preprocess.tab
2024-06-24 00:21:14.897922 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/bams/processed.aligner_input_1.fastq ...
2024-06-24 00:21:14.901527 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/bams/processed.aligner_input_2.fastq ...
2024-06-24 00:21:14.90443 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/reports/shortReadReport_1 ...
2024-06-24 00:21:16.180428 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/reports/shortReadReport_2 ...
2024-06-24 00:21:17.182397 INFO::preprocessReads.R/preprocessReads: done
2024-06-24 00:21:17.257441 INFO::alignReads.R/alignReads: starting alignment...
2024-06-24 00:21:17.262372 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:21:20.147465 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:21:20.149739 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000001/logs/progress.log
2024-06-24 00:21:22.662096 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-06-24 00:21:22.663548 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-06-24 00:21:25.196789 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-06-24 00:21:25.198252 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/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-24 00:21:27.701184 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2024-06-24 00:21:27.70436 DEBUG::tools.R/processChunks: done
2024-06-24 00:21:27.706298 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-06-24 00:21:27.893929 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-24 00:21:27.900838 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.summary_alignment.tab
2024-06-24 00:21:27.906822 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.summary_analyzed_bamstats.tab
2024-06-24 00:21:27.908478 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-24 00:21:28.127351 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.summary_target_lengths.tab
2024-06-24 00:21:28.173254 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-24 00:21:28.174299 INFO::alignReads.R/alignReads: done
2024-06-24 00:21:28.245254 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-06-24 00:21:28.263923 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:21:30.88406 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:21:30.885665 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000001/logs/progress.log
2024-06-24 00:21:33.301627 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-06-24 00:21:33.303156 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000002/logs/progress.log
2024-06-24 00:21:35.751496 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2024-06-24 00:21:35.753492 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000003/logs/progress.log
2024-06-24 00:21:38.208557 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2024-06-24 00:21:38.211093 DEBUG::tools.R/processChunks: done
2024-06-24 00:21:38.212773 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-06-24 00:21:38.225734 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.counts_exon.tab
2024-06-24 00:21:38.236992 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.counts_exon_disjoint.tab
2024-06-24 00:21:38.244222 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.counts_gene.tab
2024-06-24 00:21:38.24917 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.counts_gene_coding.tab
2024-06-24 00:21:38.254185 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.counts_gene_exonic.tab
2024-06-24 00:21:38.259186 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.counts_intergenic.tab
2024-06-24 00:21:38.268254 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.counts_intron.tab
2024-06-24 00:21:38.271536 INFO::countGenomicFeatures.R/mergeCounts: done
2024-06-24 00:21:38.276525 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.summary_counts.tab
2024-06-24 00:21:38.277982 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-06-24 00:21:38.55775 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-06-24 00:21:38.558654 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-06-24 00:21:38.630882 INFO::coverage.R/calculateCoverage: starting...
2024-06-24 00:21:38.63567 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:21:41.885835 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:21:41.887577 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000001/logs/progress.log
2024-06-24 00:21:44.038236 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-06-24 00:21:44.039804 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000002/logs/progress.log
2024-06-24 00:21:46.196743 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-06-24 00:21:46.198383 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/chunks/chunk_000003/logs/progress.log
2024-06-24 00:21:48.361972 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2024-06-24 00:21:48.365168 DEBUG::tools.R/processChunks: done
2024-06-24 00:21:50.045262 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.coverage.RData
2024-06-24 00:21:50.046966 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.coverage.bw
2024-06-24 00:21:50.062023 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.summary_coverage.tab
2024-06-24 00:21:50.063817 INFO::coverage.R/calculateCoverage: done
2024-06-24 00:21:50.067073 INFO::analyzeVariants/analyzeVariants: starting ...
2024-06-24 00:21:50.157116 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:21:53.939075 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:21:54.001784 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:21:54.015865 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:21:54.01713 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.raw_variants.RData
2024-06-24 00:21:54.018589 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.filtered_variants.RData
2024-06-24 00:21:54.019761 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-24 00:21:54.020659 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-24 00:21:54.211438 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-24 00:21:54.299012 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/results/test_pe.summary_variants.tab
2024-06-24 00:21:54.300894 INFO::analyzeVariants/analyzeVariants: done
2024-06-24 00:21:54.304321 INFO::Pipeline run successful.
2024-06-24 00:21:54.452487 INFO::mergeLanes.R/doMergeLanes: starting...
2024-06-24 00:21:54.457694 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:21:54.460098 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.adapter_contaminated_1.RData
2024-06-24 00:21:54.46312 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-24 00:21:54.465169 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.adapter_contaminated_2.RData
2024-06-24 00:21:54.477432 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-24 00:21:54.47985 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.summary_preprocess.tab
2024-06-24 00:21:54.482354 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-06-24 00:21:54.710763 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-24 00:21:54.717973 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.summary_alignment.tab
2024-06-24 00:21:54.725628 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.summary_analyzed_bamstats.tab
2024-06-24 00:21:54.727747 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-24 00:21:54.973321 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.summary_target_lengths.tab
2024-06-24 00:21:55.024051 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-24 00:21:55.054329 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-06-24 00:21:55.074826 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.counts_exon.tab
2024-06-24 00:21:55.087894 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.counts_exon_disjoint.tab
2024-06-24 00:21:55.095792 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.counts_gene.tab
2024-06-24 00:21:55.102321 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.counts_gene_coding.tab
2024-06-24 00:21:55.108005 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.counts_gene_exonic.tab
2024-06-24 00:21:55.114092 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.counts_intergenic.tab
2024-06-24 00:21:55.12663 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.counts_intron.tab
2024-06-24 00:21:55.130114 INFO::countGenomicFeatures.R/mergeCounts: done
2024-06-24 00:21:55.136279 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.summary_counts.tab
2024-06-24 00:21:55.138079 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-06-24 00:21:55.350362 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-06-24 00:21:57.88394 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.coverage.RData
2024-06-24 00:21:57.88728 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.coverage.bw
2024-06-24 00:21:57.900406 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.summary_coverage.tab
2024-06-24 00:21:57.94061 INFO::analyzeVariants/analyzeVariants: starting ...
2024-06-24 00:21:58.007154 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:22:01.146628 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:22:01.215646 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:22:01.23163 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:22:01.232919 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.raw_variants.RData
2024-06-24 00:22:01.23443 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.filtered_variants.RData
2024-06-24 00:22:01.235627 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-24 00:22:01.236616 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-24 00:22:01.442584 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-24 00:22:01.535607 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.mergeLanes.1bb82450758f62/merged/results/merged.summary_variants.tab
2024-06-24 00:22:01.537891 INFO::analyzeVariants/analyzeVariants: done
2024-06-24 00:22:01.541408 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/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:22:01.800851 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-24 00:22:01.82463 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:22:01.842829 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-24 00:22:01.84571 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:22:05.171475 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:22:05.173488 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/chunks/chunk_000001/logs/progress.log
2024-06-24 00:22:07.7936 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-06-24 00:22:07.841966 DEBUG::tools.R/processChunks: done
2024-06-24 00:22:07.844567 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:22:07.846202 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/results/test_pe.adapter_contaminated_1.RData
2024-06-24 00:22:07.848011 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-24 00:22:07.849545 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/results/test_pe.adapter_contaminated_2.RData
2024-06-24 00:22:07.856624 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-24 00:22:07.858794 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/results/test_pe.summary_preprocess.tab
2024-06-24 00:22:07.861169 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/bams/processed.aligner_input_1.fastq ...
2024-06-24 00:22:07.865826 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/bams/processed.aligner_input_2.fastq ...
2024-06-24 00:22:07.869195 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/reports/shortReadReport_1 ...
2024-06-24 00:22:09.228246 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.preprocessReads.1bb82418f08803/reports/shortReadReport_2 ...
2024-06-24 00:22:10.326306 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:22:10.579898 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-24 00:22:10.586331 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:22:10.590165 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-06-24 00:22:10.592705 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:22:14.207991 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:22:14.209695 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/chunks/chunk_000001/logs/progress.log
2024-06-24 00:22:16.877983 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-06-24 00:22:16.880603 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/chunks/chunk_000002/logs/progress.log
2024-06-24 00:22:19.486638 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-06-24 00:22:19.488276 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/chunks/chunk_000003/logs/progress.log
2024-06-24 00:22:22.068619 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-06-24 00:22:22.112662 DEBUG::tools.R/processChunks: done
2024-06-24 00:22:22.11705 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:22:22.119593 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/results/test_pe.adapter_contaminated_1.RData
2024-06-24 00:22:22.121939 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-24 00:22:22.123609 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/results/test_pe.adapter_contaminated_2.RData
2024-06-24 00:22:22.1323 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-24 00:22:22.134239 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/results/test_pe.summary_preprocess.tab
2024-06-24 00:22:22.136846 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/bams/processed.aligner_input_1.fastq ...
2024-06-24 00:22:22.140724 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/bams/processed.aligner_input_2.fastq ...
2024-06-24 00:22:22.143924 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/reports/shortReadReport_1 ...
2024-06-24 00:22:23.475765 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.preprocessReads.minichunks.1bb82448b06048/reports/shortReadReport_2 ...
2024-06-24 00:22:24.567385 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:22:24.849629 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-24 00:22:24.872327 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-06-24 00:22:24.875563 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:22:28.381449 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:22:28.382983 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpurojSL/test.preprocessReads_single_end.1bb8246d904b6e/chunks/chunk_000001/logs/progress.log
2024-06-24 00:22:30.773411 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-06-24 00:22:30.784734 DEBUG::tools.R/processChunks: done
2024-06-24 00:22:30.787535 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:22:30.789202 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads_single_end.1bb8246d904b6e/results/test_se.adapter_contaminated_1.RData
2024-06-24 00:22:30.796554 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-24 00:22:30.798517 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.preprocessReads_single_end.1bb8246d904b6e/results/test_se.summary_preprocess.tab
2024-06-24 00:22:30.800688 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpurojSL/test.preprocessReads_single_end.1bb8246d904b6e/bams/processed.aligner_input_1.fastq ...
2024-06-24 00:22:30.804162 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpurojSL/test.preprocessReads_single_end.1bb8246d904b6e/reports/shortReadReport_1 ...
2024-06-24 00:22:32.150822 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



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



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



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



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



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



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:22:32.77986 INFO::preprocessReads.R/preprocessReads: starting...
2024-06-24 00:22:32.803192 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-06-24 00:22:32.80839 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-06-24 00:22:32.81102 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:22:35.739004 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:22:35.740482 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-06-24 00:22:38.545487 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-06-24 00:22:38.589545 DEBUG::tools.R/processChunks: done
2024-06-24 00:22:38.591972 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-06-24 00:22:38.593573 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-06-24 00:22:38.595506 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-06-24 00:22:38.596994 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-06-24 00:22:38.603611 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-24 00:22:38.605511 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-06-24 00:22:38.607609 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-06-24 00:22:38.612056 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-06-24 00:22:38.615609 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-06-24 00:22:40.016912 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-06-24 00:22:41.201824 INFO::preprocessReads.R/preprocessReads: done
2024-06-24 00:22:41.284129 INFO::alignReads.R/alignReads: starting alignment...
2024-06-24 00:22:41.289089 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:22:44.232506 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:22:44.234328 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-24 00:22:48.561441 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.072 minutes
2024-06-24 00:22:48.563621 DEBUG::tools.R/processChunks: done
2024-06-24 00:22:48.564977 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-06-24 00:22:48.613262 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-06-24 00:22:48.619248 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-06-24 00:22:48.623966 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-06-24 00:22:48.625844 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-06-24 00:22:48.779226 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-06-24 00:22:48.827067 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-06-24 00:22:48.828157 INFO::alignReads.R/alignReads: done
2024-06-24 00:22:48.912821 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-06-24 00:22:48.931476 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:22:52.666421 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:22:52.668272 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-06-24 00:22:55.160611 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-06-24 00:22:55.162858 DEBUG::tools.R/processChunks: done
2024-06-24 00:22:55.16447 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-06-24 00:22:55.173959 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-06-24 00:22:55.18314 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-06-24 00:22:55.189906 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-06-24 00:22:55.194138 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-06-24 00:22:55.197962 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-06-24 00:22:55.201685 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-06-24 00:22:55.207571 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-06-24 00:22:55.211385 INFO::countGenomicFeatures.R/mergeCounts: done
2024-06-24 00:22:55.214828 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-06-24 00:22:55.216497 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-06-24 00:22:55.43496 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-06-24 00:22:55.435936 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-06-24 00:22:55.509488 INFO::coverage.R/calculateCoverage: starting...
2024-06-24 00:22:55.513781 DEBUG::tools.R/processChunks: starting...
2024-06-24 00:22:58.457539 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-06-24 00:22:58.459199 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-06-24 00:23:00.778933 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-06-24 00:23:00.781363 DEBUG::tools.R/processChunks: done
2024-06-24 00:23:02.007717 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-06-24 00:23:02.009541 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-06-24 00:23:02.086736 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-06-24 00:23:02.0881 INFO::coverage.R/calculateCoverage: done
2024-06-24 00:23:02.089788 INFO::analyzeVariants/analyzeVariants: starting ...
2024-06-24 00:23:02.226811 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-06-24 00:23:13.627386 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-06-24 00:23:13.738476 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-06-24 00:23:13.763612 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-06-24 00:23:13.765631 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-06-24 00:23:13.769478 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-06-24 00:23:13.771429 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-06-24 00:23:13.772931 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-06-24 00:23:14.107777 INFO::analyzeVariants.R/writeVCF: ...done
2024-06-24 00:23:14.248531 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-06-24 00:23:14.252234 INFO::analyzeVariants/analyzeVariants: done
2024-06-24 00:23:14.266389 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpurojSL/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-06-24 00:23:14.511525 INFO::io.R/saveWithID: saving file= /tmp/RtmpurojSL/test.calcTargetLengths.1bb8243687e742/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 24 00:23:50 2024 
*********************************************** 
Number of test functions: 61 
Number of deactivated test functions: 10 
Number of errors: 0 
Number of failures: 0 

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



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (25.5 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (16.64 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.49 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (64.62 seconds)
test.wrap.callVariants: (4 checks) ... OK (10.11 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (19.92 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.95 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.13 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (1.68 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (25.66 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (22.4 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.64 seconds)
test.isSparse: (5 checks) ... OK (0.09 seconds)
test.mergeCoverage: (1 checks) ... OK (1.47 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.12 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.14 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.3 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.34 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-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.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.45 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.41 seconds)
test.getRRNAIds: (1 checks) ... OK (0.28 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.23 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.09 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.05 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.gatk.R 
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.13 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.17 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.32 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.14 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.17 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (1.42 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.12 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.21 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (58.19 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.picard.R 
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (8.76 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (14.24 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (7.58 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.08 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.09 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.13 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (41.76 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.24 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (35.1 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.02 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.16 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.5 seconds) 

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

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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