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.1 (2024-06-14) -- "Race for Your Life"	4763
palomino7	Windows Server 2022 Datacenter	x64	4.4.1 (2024-06-14 ucrt) -- "Race for Your Life"	4500
merida1	macOS 12.7.5 Monterey	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4530
kjohnson1	macOS 13.6.6 Ventura	arm64	4.4.1 (2024-06-14) -- "Race for Your Life"	4480
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-10-17 01:27:47 -0400 (Thu, 17 Oct 2024)

EndedAt: 2024-10-17 01:41:16 -0400 (Thu, 17 Oct 2024)

EllapsedTime: 809.8 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.1 (2024-06-14)
* 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.5 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.1 (2024-06-14) -- "Race for Your Life"
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/Rtmpgxbre8/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-10-17 01:33:28.461482 INFO::preprocessReads.R/preprocessReads: starting...
2024-10-17 01:33:28.469573 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-10-17 01:33:28.472913 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-10-17 01:33:28.47506 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:33:31.082014 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:33:31.083431 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/chunks/chunk_000001/logs/progress.log
2024-10-17 01:33:33.804857 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-10-17 01:33:33.806339 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/chunks/chunk_000002/logs/progress.log
2024-10-17 01:33:36.514748 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-10-17 01:33:36.516175 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/chunks/chunk_000003/logs/progress.log
2024-10-17 01:33:39.192927 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-10-17 01:33:39.223376 DEBUG::tools.R/processChunks: done
2024-10-17 01:33:39.22754 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:33:39.22979 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/results/test_pe.adapter_contaminated_1.RData
2024-10-17 01:33:39.232435 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-10-17 01:33:39.234045 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/results/test_pe.adapter_contaminated_2.RData
2024-10-17 01:33:39.24302 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-10-17 01:33:39.245145 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/results/test_pe.summary_preprocess.tab
2024-10-17 01:33:39.248439 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/bams/processed.aligner_input_1.fastq ...
2024-10-17 01:33:39.253192 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/bams/processed.aligner_input_2.fastq ...
2024-10-17 01:33:39.256406 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/reports/shortReadReport_1 ...
2024-10-17 01:33:40.539445 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/reports/shortReadReport_2 ...
2024-10-17 01:33:41.536093 INFO::preprocessReads.R/preprocessReads: done
2024-10-17 01:33:41.60271 INFO::alignReads.R/alignReads: starting alignment...
2024-10-17 01:33:41.60875 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:33:44.401066 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:33:44.402653 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/chunks/chunk_000001/logs/progress.log
2024-10-17 01:33:47.178093 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-10-17 01:33:47.180675 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/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-10-17 01:33:49.823903 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-10-17 01:33:49.825408 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/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-10-17 01:33:52.52902 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-10-17 01:33:52.533883 DEBUG::tools.R/processChunks: done
2024-10-17 01:33:52.536419 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-10-17 01:33:52.817842 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-10-17 01:33:52.828845 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/results/test_pe.summary_alignment.tab
2024-10-17 01:33:52.837472 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/results/test_pe.summary_analyzed_bamstats.tab
2024-10-17 01:33:52.839613 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-10-17 01:33:53.108509 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.575c212735d74/results/test_pe.summary_target_lengths.tab
2024-10-17 01:33:53.159403 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-10-17 01:33:53.16055 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:33:53.435066 INFO::preprocessReads.R/preprocessReads: starting...
2024-10-17 01:33:53.438651 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-10-17 01:33:53.511214 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-10-17 01:33:53.516381 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-10-17 01:33:53.519474 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-10-17 01:33:53.521524 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:33:56.168561 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:33:56.170062 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/chunks/chunk_000001/logs/progress.log
2024-10-17 01:33:58.85468 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-10-17 01:33:58.85603 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/chunks/chunk_000002/logs/progress.log
2024-10-17 01:34:01.559628 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2024-10-17 01:34:01.561064 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/chunks/chunk_000003/logs/progress.log
2024-10-17 01:34:04.296942 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-10-17 01:34:04.298607 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/chunks/chunk_000004/logs/progress.log
2024-10-17 01:34:06.95682 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.044 minutes
2024-10-17 01:34:06.987968 DEBUG::tools.R/processChunks: done
2024-10-17 01:34:06.991381 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:34:06.993775 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/results/test_pe.adapter_contaminated_1.RData
2024-10-17 01:34:06.996609 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-10-17 01:34:06.998207 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/results/test_pe.adapter_contaminated_2.RData
2024-10-17 01:34:07.00839 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-10-17 01:34:07.010691 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/results/test_pe.summary_preprocess.tab
2024-10-17 01:34:07.014176 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/bams/processed.aligner_input_1.fastq ...
2024-10-17 01:34:07.019208 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/bams/processed.aligner_input_2.fastq ...
2024-10-17 01:34:07.023023 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/reports/shortReadReport_1 ...
2024-10-17 01:34:08.312732 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.alignReads.sparsechunks.575c25e1551d/reports/shortReadReport_2 ...
2024-10-17 01:34:09.279056 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:34:09.461375 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-10-17 01:34:09.465893 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/Rtmpgxbre8/test.alignReadsOneSingleEnd.575c2553614e7/bams/test.alignReads /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-10-17 01:34:09.662107 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-10-17 01:34:09.746782 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReadsOneSingleEnd.575c2553614e7/results/test.alignReads.summary_alignment.tab
2024-10-17 01:34:09.786979 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.alignReadsOneSingleEnd.575c2553614e7/results/test.alignReads.summary_analyzed_bamstats.tab
2024-10-17 01:34:09.788453 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/Rtmpgxbre8/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-10-17 01:34:10.089955 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.genotype.575c22e235e7c/results/test_pe.coverage.RData
2024-10-17 01:34:10.091902 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpgxbre8/test.genotype.575c22e235e7c/results/test_pe.coverage.bw
2024-10-17 01:34:10.206214 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.genotype.575c22e235e7c/results/test_pe.summary_coverage.tab
2024-10-17 01:34:10.208089 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:34:20.533859 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:34:20.61713 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:34:20.63353 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:34:20.635168 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.genotype.575c22e235e7c/results/test_pe.raw_variants.RData
2024-10-17 01:34:20.637629 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.genotype.575c22e235e7c/results/test_pe.filtered_variants.RData
2024-10-17 01:34:20.639062 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-10-17 01:34:20.640304 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-10-17 01:34:21.054322 INFO::analyzeVariants.R/writeVCF: ...done
2024-10-17 01:34:21.055568 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-10-17 01:35:15.84544 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-10-17 01:35:16.224403 INFO::analyzeVariants.R/writeVCF: ...done
2024-10-17 01:35:16.225282 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/Rtmpgxbre8/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-10-17 01:35:16.645072 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:35:26.365019 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:35:26.438292 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:35:26.453167 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:35:26.454486 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.575c243142f4c/results/test_pe.raw_variants.RData
2024-10-17 01:35:26.456781 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.575c243142f4c/results/test_pe.filtered_variants.RData
2024-10-17 01:35:26.458019 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:35:26.598467 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:35:36.390091 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:35:36.448134 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:35:36.464095 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:35:36.465438 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.filters.575c21535b512/results/test_pe.raw_variants.RData
2024-10-17 01:35:36.467819 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.filters.575c21535b512/results/test_pe.filtered_variants.RData
2024-10-17 01:35:36.469023 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-10-17 01:35:36.470498 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:35:46.730187 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:35:46.766407 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:35:46.782293 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:35:46.783631 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.filters.575c21535b512/results/test_pe.raw_variants.RData
2024-10-17 01:35:46.786081 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.filters.575c21535b512/results/test_pe.filtered_variants.RData
2024-10-17 01:35:46.787991 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:35:47.05055 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:35:47.052125 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-10-17 01:35:49.678045 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:35:49.742586 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:35:49.756921 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:35:49.758117 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.which.575c258a4fea0/results/test_pe.raw_variants.RData
2024-10-17 01:35:49.759584 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.wrap.callVariants.which.575c258a4fea0/results/test_pe.filtered_variants.RData
2024-10-17 01:35:49.760705 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:35:49.892394 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-10-17 01:35:49.893539 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:35:51.310239 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-10-17 01:35:51.488707 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-10-17 01:36:41.395293 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/asiqketd/merged/results/bla.coverage.RData
2024-10-17 01:36:41.399119 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpgxbre8/asiqketd/merged/results/bla.coverage.bw
2024-10-17 01:36:41.470246 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/asiqketd/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-10-17 01:36:42.485366 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/omdbtgvc/merged/results/bla.coverage.RData
2024-10-17 01:36:42.486989 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpgxbre8/omdbtgvc/merged/results/bla.coverage.bw
2024-10-17 01:36:42.49768 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/omdbtgvc/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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/Rtmpgxbre8/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-10-17 01:36:43.676017 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-10-17 01:36:43.677066 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpgxbre8/test.detectRRNA.575c24bc2bf46/bams/rRNA_contam/input1.fastq
2024-10-17 01:36:43.680056 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/Rtmpgxbre8/test.detectRRNA.575c24bc2bf46/bams/rRNA_contam/test_se /tmp/Rtmpgxbre8/test.detectRRNA.575c24bc2bf46/bams/rRNA_contam/input1.fastq 2>&1
2024-10-17 01:36:43.931931 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-10-17 01:36:43.932909 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:36:44.078662 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-10-17 01:36:44.079627 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpgxbre8/test.detectRRNA.paired_end.575c2eabe517/bams/rRNA_contam/input1.fastq
2024-10-17 01:36:44.081017 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpgxbre8/test.detectRRNA.paired_end.575c2eabe517/bams/rRNA_contam/input2.fastq
2024-10-17 01:36:44.08309 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/Rtmpgxbre8/test.detectRRNA.paired_end.575c2eabe517/bams/rRNA_contam/test_pe /tmp/Rtmpgxbre8/test.detectRRNA.paired_end.575c2eabe517/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmpgxbre8/test.detectRRNA.paired_end.575c2eabe517/bams/rRNA_contam/input2.fastq 2>&1
2024-10-17 01:36:44.364427 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-10-17 01:36:44.365418 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-10-17 01:36:44.383562 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/Rtmpgxbre8/test_get_rRNA_idstcmhyjal/test_pe /tmp/Rtmpgxbre8/test_get_rRNA_idstcmhyjal/1.fastq -a paired /tmp/Rtmpgxbre8/test_get_rRNA_idstcmhyjal/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-10-17 01:36:44.673465 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/Rtmpgxbre8/test_get_rRNAIds_randommswirgcy/test_pe /tmp/Rtmpgxbre8/test_get_rRNAIds_randommswirgcy/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-10-17 01:36:44.892362 INFO::filterQuality.R/filterQuality: filterByLength...
2024-10-17 01:36:44.893765 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-10-17 01:36:44.894586 INFO::filterQuality.R/filterByLength: done
2024-10-17 01:36:44.939048 INFO::filterQuality.R/filterQuality: filterByLength...
2024-10-17 01:36:44.93994 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-10-17 01:36:44.940739 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-10-17 01:36:44.986495 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-10-17 01:36:44.99482 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-10-17 01:36:44.995854 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-10-17 01:36:44.999891 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-10-17 01:36:45.000762 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-10-17 01:36:45.004654 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-10-17 01:36:45.005513 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-10-17 01:36:45.009357 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



Executing test function test.realignIndelsGATK.parallel  ... Timing stopped at: 0 0 0.001
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/Rtmpgxbre8/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-10-17 01:36:45.288055 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-10-17 01:36:45.290229 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/Rtmpgxbre8/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-10-17 01:36:45.455631 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-10-17 01:36:45.550856 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-10-17 01:36:45.553534 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-10-17 01:36:45.555593 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/Rtmpgxbre8/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-10-17 01:36:45.769147 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/Rtmpgxbre8/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-10-17 01:36:45.907631 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/Rtmpgxbre8/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-10-17 01:36:46.071595 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-10-17 01:36:46.145539 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-10-17 01:36:46.147996 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-10-17 01:36:46.150114 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/Rtmpgxbre8/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-10-17 01:36:46.35909 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-10-17 01:36:46.401658 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-10-17 01:36:46.403972 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-10-17 01:36:46.40618 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/Rtmpgxbre8/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/Rtmpgxbre8/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-10-17 01:36:47.093658 INFO::preprocessReads.R/preprocessReads: starting...
2024-10-17 01:36:47.099861 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-10-17 01:36:47.103619 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-10-17 01:36:47.106088 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:36:50.278415 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:36:50.280333 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000001/logs/progress.log
2024-10-17 01:36:52.847462 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-10-17 01:36:52.849022 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000002/logs/progress.log
2024-10-17 01:36:55.432451 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-10-17 01:36:55.434832 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000003/logs/progress.log
2024-10-17 01:36:58.037171 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-10-17 01:36:58.077336 DEBUG::tools.R/processChunks: done
2024-10-17 01:36:58.080299 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:36:58.082045 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.adapter_contaminated_1.RData
2024-10-17 01:36:58.084139 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-10-17 01:36:58.085721 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.adapter_contaminated_2.RData
2024-10-17 01:36:58.093741 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-10-17 01:36:58.095387 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.summary_preprocess.tab
2024-10-17 01:36:58.097703 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/bams/processed.aligner_input_1.fastq ...
2024-10-17 01:36:58.103079 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/bams/processed.aligner_input_2.fastq ...
2024-10-17 01:36:58.10625 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/reports/shortReadReport_1 ...
2024-10-17 01:36:59.400528 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/reports/shortReadReport_2 ...
2024-10-17 01:37:00.402891 INFO::preprocessReads.R/preprocessReads: done
2024-10-17 01:37:00.523823 INFO::alignReads.R/alignReads: starting alignment...
2024-10-17 01:37:00.528264 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:37:03.336852 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:37:03.338618 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000001/logs/progress.log
2024-10-17 01:37:05.901354 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-10-17 01:37:05.903802 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/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-10-17 01:37:08.456315 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-10-17 01:37:08.457862 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/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-10-17 01:37:10.986974 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2024-10-17 01:37:10.989149 DEBUG::tools.R/processChunks: done
2024-10-17 01:37:10.990482 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-10-17 01:37:11.165919 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-10-17 01:37:11.172804 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.summary_alignment.tab
2024-10-17 01:37:11.178869 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.summary_analyzed_bamstats.tab
2024-10-17 01:37:11.180555 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-10-17 01:37:11.398304 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.summary_target_lengths.tab
2024-10-17 01:37:11.443107 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-10-17 01:37:11.444137 INFO::alignReads.R/alignReads: done
2024-10-17 01:37:11.505966 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-10-17 01:37:11.526043 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:37:14.621264 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:37:14.623063 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000001/logs/progress.log
2024-10-17 01:37:17.022707 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-10-17 01:37:17.024353 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000002/logs/progress.log
2024-10-17 01:37:19.469594 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.041 minutes
2024-10-17 01:37:19.472146 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000003/logs/progress.log
2024-10-17 01:37:21.944428 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.041 minutes
2024-10-17 01:37:21.946844 DEBUG::tools.R/processChunks: done
2024-10-17 01:37:21.94872 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-10-17 01:37:21.962819 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.counts_exon.tab
2024-10-17 01:37:21.975 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.counts_exon_disjoint.tab
2024-10-17 01:37:21.982707 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.counts_gene.tab
2024-10-17 01:37:21.988128 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.counts_gene_coding.tab
2024-10-17 01:37:21.993598 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.counts_gene_exonic.tab
2024-10-17 01:37:21.998999 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.counts_intergenic.tab
2024-10-17 01:37:22.008635 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.counts_intron.tab
2024-10-17 01:37:22.012148 INFO::countGenomicFeatures.R/mergeCounts: done
2024-10-17 01:37:22.017704 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.summary_counts.tab
2024-10-17 01:37:22.019404 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-10-17 01:37:22.310414 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-10-17 01:37:22.311344 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-10-17 01:37:22.393976 INFO::coverage.R/calculateCoverage: starting...
2024-10-17 01:37:22.399253 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:37:25.328174 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:37:25.329821 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000001/logs/progress.log
2024-10-17 01:37:27.500495 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-10-17 01:37:27.502085 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000002/logs/progress.log
2024-10-17 01:37:29.670609 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-10-17 01:37:29.672114 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/chunks/chunk_000003/logs/progress.log
2024-10-17 01:37:31.826338 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2024-10-17 01:37:31.828619 DEBUG::tools.R/processChunks: done
2024-10-17 01:37:33.199089 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.coverage.RData
2024-10-17 01:37:33.200567 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.coverage.bw
2024-10-17 01:37:33.211573 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.summary_coverage.tab
2024-10-17 01:37:33.212738 INFO::coverage.R/calculateCoverage: done
2024-10-17 01:37:33.219959 INFO::analyzeVariants/analyzeVariants: starting ...
2024-10-17 01:37:33.309997 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:37:36.231387 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:37:36.296906 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:37:36.311638 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:37:36.31288 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.raw_variants.RData
2024-10-17 01:37:36.314399 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.filtered_variants.RData
2024-10-17 01:37:36.31558 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-10-17 01:37:36.316501 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-10-17 01:37:36.515528 INFO::analyzeVariants.R/writeVCF: ...done
2024-10-17 01:37:36.60339 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/results/test_pe.summary_variants.tab
2024-10-17 01:37:36.605633 INFO::analyzeVariants/analyzeVariants: done
2024-10-17 01:37:36.609764 INFO::Pipeline run successful.
2024-10-17 01:37:36.76617 INFO::mergeLanes.R/doMergeLanes: starting...
2024-10-17 01:37:36.772945 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:37:36.775995 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.adapter_contaminated_1.RData
2024-10-17 01:37:36.779945 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-10-17 01:37:36.78248 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.adapter_contaminated_2.RData
2024-10-17 01:37:36.797911 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-10-17 01:37:36.801141 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.summary_preprocess.tab
2024-10-17 01:37:36.804232 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-10-17 01:37:37.069629 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-10-17 01:37:37.077627 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.summary_alignment.tab
2024-10-17 01:37:37.086656 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.summary_analyzed_bamstats.tab
2024-10-17 01:37:37.089136 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-10-17 01:37:37.349981 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.summary_target_lengths.tab
2024-10-17 01:37:37.403325 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-10-17 01:37:37.455309 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-10-17 01:37:37.478028 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.counts_exon.tab
2024-10-17 01:37:37.491904 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.counts_exon_disjoint.tab
2024-10-17 01:37:37.500064 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.counts_gene.tab
2024-10-17 01:37:37.505738 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.counts_gene_coding.tab
2024-10-17 01:37:37.51104 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.counts_gene_exonic.tab
2024-10-17 01:37:37.516757 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.counts_intergenic.tab
2024-10-17 01:37:37.528817 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.counts_intron.tab
2024-10-17 01:37:37.532368 INFO::countGenomicFeatures.R/mergeCounts: done
2024-10-17 01:37:37.538919 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.summary_counts.tab
2024-10-17 01:37:37.540862 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-10-17 01:37:37.761987 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-10-17 01:37:39.791708 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.coverage.RData
2024-10-17 01:37:39.794074 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.coverage.bw
2024-10-17 01:37:39.804985 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.summary_coverage.tab
2024-10-17 01:37:39.844536 INFO::analyzeVariants/analyzeVariants: starting ...
2024-10-17 01:37:39.919364 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:37:43.062075 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:37:43.12851 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:37:43.145072 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:37:43.146425 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.raw_variants.RData
2024-10-17 01:37:43.147923 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.filtered_variants.RData
2024-10-17 01:37:43.149107 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-10-17 01:37:43.150032 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-10-17 01:37:43.364268 INFO::analyzeVariants.R/writeVCF: ...done
2024-10-17 01:37:43.457021 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.mergeLanes.575c272d0382d/merged/results/merged.summary_variants.tab
2024-10-17 01:37:43.459009 INFO::analyzeVariants/analyzeVariants: done
2024-10-17 01:37:43.46234 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:37:43.74003 INFO::preprocessReads.R/preprocessReads: starting...
2024-10-17 01:37:43.760448 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-10-17 01:37:43.77892 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-10-17 01:37:43.781705 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:37:46.919615 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:37:46.921024 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/chunks/chunk_000001/logs/progress.log
2024-10-17 01:37:49.500895 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-10-17 01:37:49.54044 DEBUG::tools.R/processChunks: done
2024-10-17 01:37:49.542694 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:37:49.544252 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/results/test_pe.adapter_contaminated_1.RData
2024-10-17 01:37:49.545884 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-10-17 01:37:49.547228 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/results/test_pe.adapter_contaminated_2.RData
2024-10-17 01:37:49.553521 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-10-17 01:37:49.555205 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/results/test_pe.summary_preprocess.tab
2024-10-17 01:37:49.557088 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/bams/processed.aligner_input_1.fastq ...
2024-10-17 01:37:49.560378 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/bams/processed.aligner_input_2.fastq ...
2024-10-17 01:37:49.5643 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/reports/shortReadReport_1 ...
2024-10-17 01:37:50.841643 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.preprocessReads.575c25742f482/reports/shortReadReport_2 ...
2024-10-17 01:37:51.844984 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:37:52.115935 INFO::preprocessReads.R/preprocessReads: starting...
2024-10-17 01:37:52.122226 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-10-17 01:37:52.126045 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-10-17 01:37:52.128554 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:37:55.047308 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:37:55.048842 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/chunks/chunk_000001/logs/progress.log
2024-10-17 01:37:57.64827 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-10-17 01:37:57.650745 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/chunks/chunk_000002/logs/progress.log
2024-10-17 01:38:00.227132 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-10-17 01:38:00.229247 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/chunks/chunk_000003/logs/progress.log
2024-10-17 01:38:02.816439 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-10-17 01:38:02.853784 DEBUG::tools.R/processChunks: done
2024-10-17 01:38:02.856753 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:38:02.858542 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/results/test_pe.adapter_contaminated_1.RData
2024-10-17 01:38:02.860716 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-10-17 01:38:02.862355 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/results/test_pe.adapter_contaminated_2.RData
2024-10-17 01:38:02.870622 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-10-17 01:38:02.872473 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/results/test_pe.summary_preprocess.tab
2024-10-17 01:38:02.874871 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/bams/processed.aligner_input_1.fastq ...
2024-10-17 01:38:02.880214 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/bams/processed.aligner_input_2.fastq ...
2024-10-17 01:38:02.884108 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/reports/shortReadReport_1 ...
2024-10-17 01:38:04.13956 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.preprocessReads.minichunks.575c21b77795c/reports/shortReadReport_2 ...
2024-10-17 01:38:05.125136 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:38:05.402461 INFO::preprocessReads.R/preprocessReads: starting...
2024-10-17 01:38:05.422017 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-10-17 01:38:05.424787 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:38:08.207487 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:38:08.208933 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpgxbre8/test.preprocessReads_single_end.575c2d320a03/chunks/chunk_000001/logs/progress.log
2024-10-17 01:38:10.542699 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-10-17 01:38:10.552306 DEBUG::tools.R/processChunks: done
2024-10-17 01:38:10.554856 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:38:10.556372 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads_single_end.575c2d320a03/results/test_se.adapter_contaminated_1.RData
2024-10-17 01:38:10.562691 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-10-17 01:38:10.564437 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.preprocessReads_single_end.575c2d320a03/results/test_se.summary_preprocess.tab
2024-10-17 01:38:10.566323 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpgxbre8/test.preprocessReads_single_end.575c2d320a03/bams/processed.aligner_input_1.fastq ...
2024-10-17 01:38:10.569665 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpgxbre8/test.preprocessReads_single_end.575c2d320a03/reports/shortReadReport_1 ...
2024-10-17 01:38:11.825213 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-10-17 01:38:12.406308 INFO::preprocessReads.R/preprocessReads: starting...
2024-10-17 01:38:12.426307 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-10-17 01:38:12.445678 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-10-17 01:38:12.44822 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:38:16.561302 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:38:16.562878 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-10-17 01:38:19.27968 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-10-17 01:38:19.317477 DEBUG::tools.R/processChunks: done
2024-10-17 01:38:19.319779 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-10-17 01:38:19.321298 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-10-17 01:38:19.32301 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-10-17 01:38:19.324385 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-10-17 01:38:19.330449 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-10-17 01:38:19.332193 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-10-17 01:38:19.33421 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-10-17 01:38:19.338049 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-10-17 01:38:19.341581 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-10-17 01:38:20.71783 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-10-17 01:38:21.866631 INFO::preprocessReads.R/preprocessReads: done
2024-10-17 01:38:21.967939 INFO::alignReads.R/alignReads: starting alignment...
2024-10-17 01:38:21.972892 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:38:25.337133 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:38:25.338945 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-10-17 01:38:29.705563 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.073 minutes
2024-10-17 01:38:29.708117 DEBUG::tools.R/processChunks: done
2024-10-17 01:38:29.709588 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-10-17 01:38:29.743922 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-10-17 01:38:29.750385 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-10-17 01:38:29.755649 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-10-17 01:38:29.757684 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-10-17 01:38:29.956266 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-10-17 01:38:30.00462 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-10-17 01:38:30.005662 INFO::alignReads.R/alignReads: done
2024-10-17 01:38:30.078351 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-10-17 01:38:30.097443 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:38:33.098214 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:38:33.099958 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-10-17 01:38:35.644987 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-10-17 01:38:35.649476 DEBUG::tools.R/processChunks: done
2024-10-17 01:38:35.652773 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-10-17 01:38:35.670575 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-10-17 01:38:35.688384 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-10-17 01:38:35.701057 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-10-17 01:38:35.708827 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-10-17 01:38:35.716639 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-10-17 01:38:35.72402 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-10-17 01:38:35.735465 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-10-17 01:38:35.7435 INFO::countGenomicFeatures.R/mergeCounts: done
2024-10-17 01:38:35.750508 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-10-17 01:38:35.754165 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-10-17 01:38:36.196968 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-10-17 01:38:36.198561 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-10-17 01:38:36.418658 INFO::coverage.R/calculateCoverage: starting...
2024-10-17 01:38:36.425922 DEBUG::tools.R/processChunks: starting...
2024-10-17 01:38:41.78961 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-10-17 01:38:41.793271 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-10-17 01:38:44.708824 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2024-10-17 01:38:44.713194 DEBUG::tools.R/processChunks: done
2024-10-17 01:38:47.952192 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-10-17 01:38:47.955758 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-10-17 01:38:48.105764 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-10-17 01:38:48.108889 INFO::coverage.R/calculateCoverage: done
2024-10-17 01:38:48.111308 INFO::analyzeVariants/analyzeVariants: starting ...
2024-10-17 01:38:48.420708 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-10-17 01:39:03.998253 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-10-17 01:39:04.088123 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-10-17 01:39:04.108967 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-10-17 01:39:04.111192 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-10-17 01:39:04.114873 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-10-17 01:39:04.116884 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-10-17 01:39:04.118332 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-10-17 01:39:04.373634 INFO::analyzeVariants.R/writeVCF: ...done
2024-10-17 01:39:04.486034 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-10-17 01:39:04.488652 INFO::analyzeVariants/analyzeVariants: done
2024-10-17 01:39:04.499212 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpgxbre8/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-10-17 01:39:04.845684 INFO::io.R/saveWithID: saving file= /tmp/Rtmpgxbre8/test.calcTargetLengths.575c22b8e403f/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 -- Thu Oct 17 01:39:24 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 (26.05 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (16.11 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.51 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 (66.73 seconds)
test.wrap.callVariants: (4 checks) ... OK (9.93 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (20.33 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (2.97 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.38 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (22.57 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.62 seconds)
test.isSparse: (5 checks) ... OK (0.08 seconds)
test.mergeCoverage: (1 checks) ... OK (1.24 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.05 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.35 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.4 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.43 seconds)
test.getRRNAIds: (1 checks) ... OK (0.29 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.05 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.04 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.gatk.R 
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.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.18 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.31 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.14 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.16 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.54 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.13 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.17 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (56.7 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.36 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (13.28 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (6.7 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.08 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 (52.32 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.35 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (19.32 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.19-bioc/R/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.06 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.15 seconds) 

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

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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