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

Hostname	OS	Arch (*)	R version	Installed pkgs
teran2	Linux (Ubuntu 24.04.1 LTS)	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4448
nebbiolo2	Linux (Ubuntu 22.04.3 LTS)	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4455
palomino8	Windows Server 2022 Datacenter	x64	4.4.1 (2024-06-14 ucrt) -- "Race for Your Life"	4453
lconway	macOS 12.7.1 Monterey	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4486
kjohnson3	macOS 13.6.5 Ventura	arm64	4.4.1 (2024-06-14) -- "Race for Your Life"	4433
kunpeng2	Linux (openEuler 22.03 LTS-SP1)	aarch64	4.4.1 (2024-06-14) -- "Race for Your Life"	4432
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 teran2

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

raw results

Summary

Package: HTSeqGenie

Version: 4.35.0

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

StartedAt: 2024-09-24 01:39:41 -0400 (Tue, 24 Sep 2024)

EndedAt: 2024-09-24 02:19:42 -0400 (Tue, 24 Sep 2024)

EllapsedTime: 2400.3 seconds

RetCode: None

Status: TIMEOUT

CheckDir: HTSeqGenie.Rcheck

Warnings: NA

Command output

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


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

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

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

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

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

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

Installation output

HTSeqGenie.Rcheck/00install.out

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


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

Tests output

HTSeqGenie.Rcheck/tests/doRUnit.Rout


R version 4.4.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/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:44:31.860194 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-24 01:44:31.869111 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:44:31.873356 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-24 01:44:31.875355 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:44:34.631174 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:44:34.632284 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/chunks/chunk_000001/logs/progress.log
2024-09-24 01:44:37.294911 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-09-24 01:44:37.296123 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/chunks/chunk_000002/logs/progress.log
2024-09-24 01:44:39.932053 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-09-24 01:44:39.933467 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/chunks/chunk_000003/logs/progress.log
2024-09-24 01:44:42.548805 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-09-24 01:44:42.563693 DEBUG::tools.R/processChunks: done
2024-09-24 01:44:42.566701 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:44:42.568654 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/results/test_pe.adapter_contaminated_1.RData
2024-09-24 01:44:42.571118 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-24 01:44:42.572553 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/results/test_pe.adapter_contaminated_2.RData
2024-09-24 01:44:42.579725 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-09-24 01:44:42.58151 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/results/test_pe.summary_preprocess.tab
2024-09-24 01:44:42.584116 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/bams/processed.aligner_input_1.fastq ...
2024-09-24 01:44:42.589111 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/bams/processed.aligner_input_2.fastq ...
2024-09-24 01:44:42.592677 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/reports/shortReadReport_1 ...
2024-09-24 01:44:43.668835 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/reports/shortReadReport_2 ...
2024-09-24 01:44:44.421498 INFO::preprocessReads.R/preprocessReads: done
2024-09-24 01:44:44.499266 INFO::alignReads.R/alignReads: starting alignment...
2024-09-24 01:44:44.505091 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:44:47.314415 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:44:47.315848 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/chunks/chunk_000001/logs/progress.log
2024-09-24 01:44:50.197507 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2024-09-24 01:44:50.199314 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-24 01:44:52.830396 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-09-24 01:44:52.832178 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/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-09-24 01:44:55.442272 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-09-24 01:44:55.44456 DEBUG::tools.R/processChunks: done
2024-09-24 01:44:55.445717 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-24 01:44:55.623795 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-09-24 01:44:55.631349 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/results/test_pe.summary_alignment.tab
2024-09-24 01:44:55.63735 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/results/test_pe.summary_analyzed_bamstats.tab
2024-09-24 01:44:55.638684 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-09-24 01:44:55.834822 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.16161a7959933f/results/test_pe.summary_target_lengths.tab
2024-09-24 01:44:55.869768 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-09-24 01:44:55.87047 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:44:56.18057 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-24 01:44:56.184302 INFO::io.R/FastQStreamer.init: counting number of reads in file= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:44:56.248388 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-09-24 01:44:56.253246 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:44:56.256224 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-24 01:44:56.257908 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:44:59.036924 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:44:59.038019 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/chunks/chunk_000001/logs/progress.log
2024-09-24 01:45:01.637809 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-09-24 01:45:01.639172 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/chunks/chunk_000002/logs/progress.log
2024-09-24 01:45:04.225049 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-09-24 01:45:04.22638 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/chunks/chunk_000003/logs/progress.log
2024-09-24 01:45:06.933356 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.045 minutes
2024-09-24 01:45:06.934634 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/chunks/chunk_000004/logs/progress.log
2024-09-24 01:45:09.504657 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.043 minutes
2024-09-24 01:45:09.527483 DEBUG::tools.R/processChunks: done
2024-09-24 01:45:09.530431 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:45:09.532488 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/results/test_pe.adapter_contaminated_1.RData
2024-09-24 01:45:09.535079 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-24 01:45:09.536577 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/results/test_pe.adapter_contaminated_2.RData
2024-09-24 01:45:09.545069 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-09-24 01:45:09.546801 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/results/test_pe.summary_preprocess.tab
2024-09-24 01:45:09.549637 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/bams/processed.aligner_input_1.fastq ...
2024-09-24 01:45:09.554234 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/bams/processed.aligner_input_2.fastq ...
2024-09-24 01:45:09.557594 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/reports/shortReadReport_1 ...
2024-09-24 01:45:10.634649 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.alignReads.sparsechunks.16161a712bf4aa/reports/shortReadReport_2 ...
2024-09-24 01:45:11.413054 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:45:11.533604 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-09-24 01:45:11.537005 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/Rtmpsfb404/test.alignReadsOneSingleEnd.16161a6cac5534/bams/test.alignReads /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-09-24 01:45:11.737561 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-09-24 01:45:11.805358 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReadsOneSingleEnd.16161a6cac5534/results/test.alignReads.summary_alignment.tab
2024-09-24 01:45:11.842816 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.alignReadsOneSingleEnd.16161a6cac5534/results/test.alignReads.summary_analyzed_bamstats.tab
2024-09-24 01:45:11.843965 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.002 0.001 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/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:45:12.053247 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.genotype.16161a2c5202f4/results/test_pe.coverage.RData
2024-09-24 01:45:12.054559 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpsfb404/test.genotype.16161a2c5202f4/results/test_pe.coverage.bw
2024-09-24 01:45:12.139633 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.genotype.16161a2c5202f4/results/test_pe.summary_coverage.tab
2024-09-24 01:45:12.14118 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-24 01:45:19.903111 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-24 01:45:19.96594 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-24 01:45:19.978135 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-24 01:45:19.979172 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.genotype.16161a2c5202f4/results/test_pe.raw_variants.RData
2024-09-24 01:45:19.981074 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.genotype.16161a2c5202f4/results/test_pe.filtered_variants.RData
2024-09-24 01:45:19.982172 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-24 01:45:19.983076 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-24 01:45:20.283096 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-24 01:45:20.284041 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-09-24 01:46:08.481799 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-24 01:46:08.787226 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-24 01:46:08.787996 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/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:46:09.089246 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-24 01:46:16.752024 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-24 01:46:16.81014 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-24 01:46:16.823093 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-24 01:46:16.824167 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.16161a3fd6c5aa/results/test_pe.raw_variants.RData
2024-09-24 01:46:16.826161 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.16161a3fd6c5aa/results/test_pe.filtered_variants.RData
2024-09-24 01:46:16.827228 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:46:16.930386 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-24 01:46:25.331617 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-24 01:46:25.376757 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-24 01:46:25.389748 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-24 01:46:25.390969 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.filters.16161a650661ee/results/test_pe.raw_variants.RData
2024-09-24 01:46:25.393152 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.filters.16161a650661ee/results/test_pe.filtered_variants.RData
2024-09-24 01:46:25.394232 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-24 01:46:25.395426 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-24 01:46:33.424874 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-24 01:46:33.456043 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-24 01:46:33.46951 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-24 01:46:33.470598 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.filters.16161a650661ee/results/test_pe.raw_variants.RData
2024-09-24 01:46:33.472834 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.filters.16161a650661ee/results/test_pe.filtered_variants.RData
2024-09-24 01:46:33.474575 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:46:33.708483 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-24 01:46:33.709736 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-09-24 01:46:36.740608 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-24 01:46:36.799651 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-24 01:46:36.81254 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-24 01:46:36.813592 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.which.16161a167337e8/results/test_pe.raw_variants.RData
2024-09-24 01:46:36.814986 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.wrap.callVariants.which.16161a167337e8/results/test_pe.filtered_variants.RData
2024-09-24 01:46:36.816045 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:46:38.306827 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-24 01:46:38.307601 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:46:38.694951 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-24 01:46:38.831173 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-09-24 01:47:18.88901 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/gjzrewao/merged/results/bla.coverage.RData
2024-09-24 01:47:18.892186 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpsfb404/gjzrewao/merged/results/bla.coverage.bw
2024-09-24 01:47:18.937968 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/gjzrewao/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-09-24 01:47:20.084317 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/mgjnhavp/merged/results/bla.coverage.RData
2024-09-24 01:47:20.085815 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpsfb404/mgjnhavp/merged/results/bla.coverage.bw
2024-09-24 01:47:20.094805 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/mgjnhavp/merged/results/bla.summary_coverage.tab
 done successfully.



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



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



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



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



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



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



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



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



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



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



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



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:22.01902 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-09-24 01:47:22.019762 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpsfb404/test.detectRRNA.16161a4a85a2fc/bams/rRNA_contam/input1.fastq
2024-09-24 01:47:22.022122 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/Rtmpsfb404/test.detectRRNA.16161a4a85a2fc/bams/rRNA_contam/test_se /tmp/Rtmpsfb404/test.detectRRNA.16161a4a85a2fc/bams/rRNA_contam/input1.fastq 2>&1
2024-09-24 01:47:22.170773 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-09-24 01:47:22.171496 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:22.255372 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-09-24 01:47:22.256063 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpsfb404/test.detectRRNA.paired_end.16161a2fca0180/bams/rRNA_contam/input1.fastq
2024-09-24 01:47:22.257162 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpsfb404/test.detectRRNA.paired_end.16161a2fca0180/bams/rRNA_contam/input2.fastq
2024-09-24 01:47:22.258766 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/Rtmpsfb404/test.detectRRNA.paired_end.16161a2fca0180/bams/rRNA_contam/test_pe /tmp/Rtmpsfb404/test.detectRRNA.paired_end.16161a2fca0180/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmpsfb404/test.detectRRNA.paired_end.16161a2fca0180/bams/rRNA_contam/input2.fastq 2>&1
2024-09-24 01:47:22.468278 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-09-24 01:47:22.469055 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-09-24 01:47:22.482841 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/Rtmpsfb404/test_get_rRNA_idsfmkyqzei/test_pe /tmp/Rtmpsfb404/test_get_rRNA_idsfmkyqzei/1.fastq -a paired /tmp/Rtmpsfb404/test_get_rRNA_idsfmkyqzei/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-09-24 01:47:22.704193 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/Rtmpsfb404/test_get_rRNAIds_randomsevfxdrp/test_pe /tmp/Rtmpsfb404/test_get_rRNAIds_randomsevfxdrp/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-09-24 01:47:22.959631 INFO::filterQuality.R/filterQuality: filterByLength...
2024-09-24 01:47:22.960955 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-09-24 01:47:22.961587 INFO::filterQuality.R/filterByLength: done
2024-09-24 01:47:22.994196 INFO::filterQuality.R/filterQuality: filterByLength...
2024-09-24 01:47:22.994784 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-09-24 01:47:22.99541 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-09-24 01:47:23.030353 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-24 01:47:23.036652 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-09-24 01:47:23.037382 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-24 01:47:23.040453 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-09-24 01:47:23.041142 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-24 01:47:23.044194 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-09-24 01:47:23.044878 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-09-24 01:47:23.047915 INFO::preprocessReads.R/preprocessReadsChunk: done
 done successfully.



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



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



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



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



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



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



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



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



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:23.233446 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:23.235074 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.pefq.subsample  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:23.345286 INFO::io.R/FastQStreamer.init: counting number of reads in file= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:23.896893 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-09-24 01:47:23.899264 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:23.900944 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:24.046307 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:24.178241 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:24.34472 INFO::io.R/FastQStreamer.init: counting number of reads in file= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:24.40098 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-09-24 01:47:24.403288 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:24.404903 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:24.57225 INFO::io.R/FastQStreamer.init: counting number of reads in file= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:24.621674 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-09-24 01:47:24.623808 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:24.625418 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



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



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



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:47:25.202589 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-24 01:47:25.208399 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:47:25.211521 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-24 01:47:25.213703 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:47:28.381701 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:47:28.383049 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000001/logs/progress.log
2024-09-24 01:47:31.099351 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-09-24 01:47:31.100647 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000002/logs/progress.log
2024-09-24 01:47:33.592789 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-09-24 01:47:33.594212 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000003/logs/progress.log
2024-09-24 01:47:36.148787 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-09-24 01:47:36.183712 DEBUG::tools.R/processChunks: done
2024-09-24 01:47:36.185997 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:47:36.187317 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.adapter_contaminated_1.RData
2024-09-24 01:47:36.189074 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-24 01:47:36.190288 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.adapter_contaminated_2.RData
2024-09-24 01:47:36.197086 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-09-24 01:47:36.198616 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.summary_preprocess.tab
2024-09-24 01:47:36.200814 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/bams/processed.aligner_input_1.fastq ...
2024-09-24 01:47:36.205495 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/bams/processed.aligner_input_2.fastq ...
2024-09-24 01:47:36.209125 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/reports/shortReadReport_1 ...
2024-09-24 01:47:37.252144 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/reports/shortReadReport_2 ...
2024-09-24 01:47:38.592036 INFO::preprocessReads.R/preprocessReads: done
2024-09-24 01:47:38.701273 INFO::alignReads.R/alignReads: starting alignment...
2024-09-24 01:47:38.706069 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:47:42.035356 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:47:42.037116 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000001/logs/progress.log
2024-09-24 01:47:44.807567 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2024-09-24 01:47:44.808993 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000002/logs/progress.log
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-24 01:47:47.366638 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-09-24 01:47:47.368282 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/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-09-24 01:47:49.923892 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-09-24 01:47:49.926956 DEBUG::tools.R/processChunks: done
2024-09-24 01:47:49.928358 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-24 01:47:50.087522 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-09-24 01:47:50.094283 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.summary_alignment.tab
2024-09-24 01:47:50.099841 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.summary_analyzed_bamstats.tab
2024-09-24 01:47:50.101294 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-09-24 01:47:50.291139 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.summary_target_lengths.tab
2024-09-24 01:47:50.329924 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-09-24 01:47:50.330917 INFO::alignReads.R/alignReads: done
2024-09-24 01:47:50.460491 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-09-24 01:47:50.483106 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:47:54.011833 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:47:54.013618 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000001/logs/progress.log
2024-09-24 01:47:56.40675 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-09-24 01:47:56.40835 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000002/logs/progress.log
2024-09-24 01:47:58.77708 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.039 minutes
2024-09-24 01:47:58.778715 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000003/logs/progress.log
2024-09-24 01:48:01.353643 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-09-24 01:48:01.355812 DEBUG::tools.R/processChunks: done
2024-09-24 01:48:01.364268 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-09-24 01:48:01.383031 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.counts_exon.tab
2024-09-24 01:48:01.394659 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.counts_exon_disjoint.tab
2024-09-24 01:48:01.399916 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.counts_gene.tab
2024-09-24 01:48:01.40405 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.counts_gene_coding.tab
2024-09-24 01:48:01.408179 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.counts_gene_exonic.tab
2024-09-24 01:48:01.412534 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.counts_intergenic.tab
2024-09-24 01:48:01.419469 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.counts_intron.tab
2024-09-24 01:48:01.421394 INFO::countGenomicFeatures.R/mergeCounts: done
2024-09-24 01:48:01.426202 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.summary_counts.tab
2024-09-24 01:48:01.427547 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-09-24 01:48:01.666916 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-09-24 01:48:01.667646 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-09-24 01:48:01.78222 INFO::coverage.R/calculateCoverage: starting...
2024-09-24 01:48:01.786624 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:48:05.014239 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:48:05.016158 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000001/logs/progress.log
2024-09-24 01:48:07.192348 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-09-24 01:48:07.194076 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000002/logs/progress.log
2024-09-24 01:48:09.374429 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-09-24 01:48:09.376321 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/chunks/chunk_000003/logs/progress.log
2024-09-24 01:48:11.561322 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2024-09-24 01:48:11.563766 DEBUG::tools.R/processChunks: done
2024-09-24 01:48:13.058808 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.coverage.RData
2024-09-24 01:48:13.060275 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.coverage.bw
2024-09-24 01:48:13.071175 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.summary_coverage.tab
2024-09-24 01:48:13.072246 INFO::coverage.R/calculateCoverage: done
2024-09-24 01:48:13.073997 INFO::analyzeVariants/analyzeVariants: starting ...
2024-09-24 01:48:13.196434 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-24 01:48:16.454724 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-24 01:48:16.51217 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-24 01:48:16.524833 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-24 01:48:16.525824 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.raw_variants.RData
2024-09-24 01:48:16.527143 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.filtered_variants.RData
2024-09-24 01:48:16.52823 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-24 01:48:16.529052 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-24 01:48:16.69976 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-24 01:48:16.779729 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/results/test_pe.summary_variants.tab
2024-09-24 01:48:16.781772 INFO::analyzeVariants/analyzeVariants: done
2024-09-24 01:48:16.785257 INFO::Pipeline run successful.
2024-09-24 01:48:16.964228 INFO::mergeLanes.R/doMergeLanes: starting...
2024-09-24 01:48:16.969461 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:48:16.971801 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.adapter_contaminated_1.RData
2024-09-24 01:48:16.9747 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-24 01:48:16.976678 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.adapter_contaminated_2.RData
2024-09-24 01:48:16.987768 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-09-24 01:48:16.989835 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.summary_preprocess.tab
2024-09-24 01:48:16.991959 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-09-24 01:48:17.205311 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-09-24 01:48:17.21222 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.summary_alignment.tab
2024-09-24 01:48:17.219272 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.summary_analyzed_bamstats.tab
2024-09-24 01:48:17.22112 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-09-24 01:48:17.432285 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.summary_target_lengths.tab
2024-09-24 01:48:17.473408 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-09-24 01:48:17.531358 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-09-24 01:48:17.551816 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.counts_exon.tab
2024-09-24 01:48:17.561714 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.counts_exon_disjoint.tab
2024-09-24 01:48:17.567536 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.counts_gene.tab
2024-09-24 01:48:17.57267 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.counts_gene_coding.tab
2024-09-24 01:48:17.577659 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.counts_gene_exonic.tab
2024-09-24 01:48:17.582991 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.counts_intergenic.tab
2024-09-24 01:48:17.593273 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.counts_intron.tab
2024-09-24 01:48:17.595416 INFO::countGenomicFeatures.R/mergeCounts: done
2024-09-24 01:48:17.601413 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.summary_counts.tab
2024-09-24 01:48:17.602965 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-09-24 01:48:17.787093 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-09-24 01:48:19.96999 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.coverage.RData
2024-09-24 01:48:19.973573 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.coverage.bw
2024-09-24 01:48:19.984746 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.summary_coverage.tab
2024-09-24 01:48:20.041073 INFO::analyzeVariants/analyzeVariants: starting ...
2024-09-24 01:48:20.16113 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-09-24 01:48:23.063483 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-09-24 01:48:23.120373 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-09-24 01:48:23.132973 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-09-24 01:48:23.133977 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.raw_variants.RData
2024-09-24 01:48:23.135323 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.filtered_variants.RData
2024-09-24 01:48:23.136384 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-09-24 01:48:23.1372 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-09-24 01:48:23.307309 INFO::analyzeVariants.R/writeVCF: ...done
2024-09-24 01:48:23.3862 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.mergeLanes.16161a6ebd5d11/merged/results/merged.summary_variants.tab
2024-09-24 01:48:23.388235 INFO::analyzeVariants/analyzeVariants: done
2024-09-24 01:48:23.393206 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



Executing test function test.markDuplicates  ... Timing stopped at: 0.001 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/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:48:23.718492 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-24 01:48:23.725432 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:48:23.728996 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-24 01:48:23.731426 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:48:27.052116 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:48:27.053268 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/chunks/chunk_000001/logs/progress.log
2024-09-24 01:48:30.089735 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.051 minutes
2024-09-24 01:48:30.13874 DEBUG::tools.R/processChunks: done
2024-09-24 01:48:30.140655 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:48:30.141777 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/results/test_pe.adapter_contaminated_1.RData
2024-09-24 01:48:30.143182 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-24 01:48:30.144214 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/results/test_pe.adapter_contaminated_2.RData
2024-09-24 01:48:30.149188 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-09-24 01:48:30.15051 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/results/test_pe.summary_preprocess.tab
2024-09-24 01:48:30.152208 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/bams/processed.aligner_input_1.fastq ...
2024-09-24 01:48:30.156703 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/bams/processed.aligner_input_2.fastq ...
2024-09-24 01:48:30.160533 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/reports/shortReadReport_1 ...
2024-09-24 01:48:31.239967 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.preprocessReads.16161a293fb5ff/reports/shortReadReport_2 ...
2024-09-24 01:48:32.014366 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:48:32.243977 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-24 01:48:32.249593 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:48:32.252402 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-09-24 01:48:32.254458 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:48:35.866135 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:48:35.867324 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/chunks/chunk_000001/logs/progress.log
2024-09-24 01:48:38.390788 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-09-24 01:48:38.392185 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/chunks/chunk_000002/logs/progress.log
2024-09-24 01:48:40.906319 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-09-24 01:48:40.908 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/chunks/chunk_000003/logs/progress.log
2024-09-24 01:48:43.476705 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-09-24 01:48:43.510803 DEBUG::tools.R/processChunks: done
2024-09-24 01:48:43.51318 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:48:43.514516 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/results/test_pe.adapter_contaminated_1.RData
2024-09-24 01:48:43.51622 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-24 01:48:43.51738 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/results/test_pe.adapter_contaminated_2.RData
2024-09-24 01:48:43.52427 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-09-24 01:48:43.525836 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/results/test_pe.summary_preprocess.tab
2024-09-24 01:48:43.528016 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/bams/processed.aligner_input_1.fastq ...
2024-09-24 01:48:43.532438 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/bams/processed.aligner_input_2.fastq ...
2024-09-24 01:48:43.535897 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/reports/shortReadReport_1 ...
2024-09-24 01:48:44.58361 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.preprocessReads.minichunks.16161a79113c45/reports/shortReadReport_2 ...
2024-09-24 01:48:45.607916 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpsfb404/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:48:45.880468 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-24 01:48:45.902238 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-09-24 01:48:45.904696 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:48:49.270886 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:48:49.272112 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpsfb404/test.preprocessReads_single_end.16161a2d4692f1/chunks/chunk_000001/logs/progress.log
2024-09-24 01:48:51.664191 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-09-24 01:48:51.694309 DEBUG::tools.R/processChunks: done
2024-09-24 01:48:51.696587 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:48:51.698198 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads_single_end.16161a2d4692f1/results/test_se.adapter_contaminated_1.RData
2024-09-24 01:48:51.703469 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-09-24 01:48:51.704752 INFO::io.R/saveWithID: saving file= /tmp/Rtmpsfb404/test.preprocessReads_single_end.16161a2d4692f1/results/test_se.summary_preprocess.tab
2024-09-24 01:48:51.706193 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpsfb404/test.preprocessReads_single_end.16161a2d4692f1/bams/processed.aligner_input_1.fastq ...
2024-09-24 01:48:51.710277 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpsfb404/test.preprocessReads_single_end.16161a2d4692f1/reports/shortReadReport_1 ...
2024-09-24 01:48:53.062744 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= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/config/default-config.txt 
2024-09-24 01:48:53.592223 INFO::preprocessReads.R/preprocessReads: starting...
2024-09-24 01:48:53.613217 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-09-24 01:48:53.618289 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/R/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-09-24 01:48:53.620533 DEBUG::tools.R/processChunks: starting...
2024-09-24 01:48:57.284265 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-09-24 01:48:57.285585 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-09-24 01:49:00.669625 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.056 minutes
2024-09-24 01:49:00.700797 DEBUG::tools.R/processChunks: done
2024-09-24 01:49:00.702773 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-09-24 01:49:00.703925 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-09-24 01:49:00.705215 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-09-24 01:49:00.70623 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-09-24 01:49:00.711222 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-09-24 01:49:00.712541 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-09-24 01:49:00.71421 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-09-24 01:49:00.719568 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-09-24 01:49:00.723648 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-09-24 01:49:53.611198 DEBUG::tools.R/traceMem: wired.mem=-31.778828 GiB
2024-09-24 01:50:53.623774 DEBUG::tools.R/traceMem: wired.mem=-31.302283 GiB
2024-09-24 01:51:53.961231 DEBUG::tools.R/traceMem: wired.mem=-34.661347 GiB
2024-09-24 01:52:54.028586 DEBUG::tools.R/traceMem: wired.mem=-36.187730 GiB
2024-09-24 01:53:54.094207 DEBUG::tools.R/traceMem: wired.mem=-36.332712 GiB
2024-09-24 01:54:54.162011 DEBUG::tools.R/traceMem: wired.mem=-32.216822 GiB
2024-09-24 01:55:54.227988 DEBUG::tools.R/traceMem: wired.mem=-33.360703 GiB
2024-09-24 01:56:54.297929 DEBUG::tools.R/traceMem: wired.mem=-31.802479 GiB
2024-09-24 01:57:54.363239 DEBUG::tools.R/traceMem: wired.mem=-29.664907 GiB
2024-09-24 01:58:54.429904 DEBUG::tools.R/traceMem: wired.mem=-30.813753 GiB
2024-09-24 01:59:54.495405 DEBUG::tools.R/traceMem: wired.mem=-30.816023 GiB
2024-09-24 02:00:54.521361 DEBUG::tools.R/traceMem: wired.mem=-30.704546 GiB
2024-09-24 02:01:54.58778 DEBUG::tools.R/traceMem: wired.mem=-23.956648 GiB
2024-09-24 02:02:54.658214 DEBUG::tools.R/traceMem: wired.mem=-28.901446 GiB
2024-09-24 02:03:54.724181 DEBUG::tools.R/traceMem: wired.mem=-25.734312 GiB
2024-09-24 02:04:54.790414 DEBUG::tools.R/traceMem: wired.mem=-25.477091 GiB
2024-09-24 02:05:54.858145 DEBUG::tools.R/traceMem: wired.mem=-28.495573 GiB
2024-09-24 02:06:54.924126 DEBUG::tools.R/traceMem: wired.mem=-27.109208 GiB
2024-09-24 02:07:54.990585 DEBUG::tools.R/traceMem: wired.mem=-28.673143 GiB
2024-09-24 02:08:55.055615 DEBUG::tools.R/traceMem: wired.mem=-30.104433 GiB
2024-09-24 02:09:55.121904 DEBUG::tools.R/traceMem: wired.mem=-28.798235 GiB
2024-09-24 02:10:55.188708 DEBUG::tools.R/traceMem: wired.mem=-26.846278 GiB
2024-09-24 02:11:55.253983 DEBUG::tools.R/traceMem: wired.mem=-23.199224 GiB
2024-09-24 02:12:55.328038 DEBUG::tools.R/traceMem: wired.mem=-32.564515 GiB
2024-09-24 02:13:55.394104 DEBUG::tools.R/traceMem: wired.mem=-35.953799 GiB
2024-09-24 02:14:55.402205 DEBUG::tools.R/traceMem: wired.mem=-36.193751 GiB
2024-09-24 02:15:55.469531 DEBUG::tools.R/traceMem: wired.mem=-33.661030 GiB
2024-09-24 02:16:55.536569 DEBUG::tools.R/traceMem: wired.mem=-34.411631 GiB
2024-09-24 02:17:55.603411 DEBUG::tools.R/traceMem: wired.mem=-28.815077 GiB
2024-09-24 02:18:55.670779 DEBUG::tools.R/traceMem: wired.mem=-32.873574 GiB

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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