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.2 (2024-10-31) -- "Pile of Leaves"	4481
nebbiolo2	Linux (Ubuntu 24.04.1 LTS)	x86_64	4.4.2 (2024-10-31) -- "Pile of Leaves"	4479
palomino8	Windows Server 2022 Datacenter	x64	4.4.2 (2024-10-31 ucrt) -- "Pile of Leaves"	4359
lconway	macOS 12.7.1 Monterey	x86_64	4.4.1 (2024-06-14) -- "Race for Your Life"	4539
kunpeng2	Linux (openEuler 22.03 LTS-SP1)	aarch64	4.4.1 (2024-06-14) -- "Race for Your Life"	4493
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.36.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.36.0.tar.gz

StartedAt: 2024-11-20 04:26:27 -0500 (Wed, 20 Nov 2024)

EndedAt: 2024-11-20 05:06:27 -0500 (Wed, 20 Nov 2024)

EllapsedTime: 2400.6 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.36.0.tar.gz
###
##############################################################################
##############################################################################


* using log directory ‘/media/volume/teran2_disk/biocbuild/bbs-3.20-bioc/meat/HTSeqGenie.Rcheck’
* using R version 4.4.2 (2024-10-31)
* 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.36.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.2 (2024-10-31) -- "Pile of Leaves"
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, saveRDS, 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/RtmpDq0sCN/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-11-20 04:31:24.870435 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-20 04:31:24.879179 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-11-20 04:31:24.883218 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-11-20 04:31:24.885191 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:31:27.957659 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:31:27.95878 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/chunks/chunk_000001/logs/progress.log
2024-11-20 04:31:30.593261 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-11-20 04:31:30.59452 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/chunks/chunk_000002/logs/progress.log
2024-11-20 04:31:33.184533 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-11-20 04:31:33.185963 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/chunks/chunk_000003/logs/progress.log
2024-11-20 04:31:35.811301 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-11-20 04:31:35.834405 DEBUG::tools.R/processChunks: done
2024-11-20 04:31:35.837511 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:31:35.839362 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/results/test_pe.adapter_contaminated_1.RData
2024-11-20 04:31:35.841653 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-20 04:31:35.842997 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/results/test_pe.adapter_contaminated_2.RData
2024-11-20 04:31:35.85035 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-11-20 04:31:36.248072 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/results/test_pe.summary_preprocess.tab
2024-11-20 04:31:36.252976 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/bams/processed.aligner_input_1.fastq ...
2024-11-20 04:31:36.258206 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/bams/processed.aligner_input_2.fastq ...
2024-11-20 04:31:36.261999 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/reports/shortReadReport_1 ...
2024-11-20 04:31:37.368692 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/reports/shortReadReport_2 ...
2024-11-20 04:31:38.119875 INFO::preprocessReads.R/preprocessReads: done
2024-11-20 04:31:38.193483 INFO::alignReads.R/alignReads: starting alignment...
2024-11-20 04:31:38.199805 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:31:41.142664 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:31:41.144291 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/chunks/chunk_000001/logs/progress.log
2024-11-20 04:31:44.292365 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2024-11-20 04:31:44.296798 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/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-11-20 04:31:46.877974 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-11-20 04:31:46.879708 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/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-11-20 04:31:49.467886 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-11-20 04:31:49.470187 DEBUG::tools.R/processChunks: done
2024-11-20 04:31:49.471336 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-11-20 04:31:49.646204 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-20 04:31:49.653855 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/results/test_pe.summary_alignment.tab
2024-11-20 04:31:49.659962 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/results/test_pe.summary_analyzed_bamstats.tab
2024-11-20 04:31:49.661324 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-20 04:31:49.8567 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.17732bb355c5/results/test_pe.summary_target_lengths.tab
2024-11-20 04:31:49.89264 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-20 04:31:49.893317 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:31:50.145428 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-20 04:31:50.148788 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-11-20 04:31:50.211046 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-11-20 04:31:50.216689 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-11-20 04:31:50.219239 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-11-20 04:31:50.220974 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:31:53.239593 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:31:53.240744 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/chunks/chunk_000001/logs/progress.log
2024-11-20 04:31:55.892303 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-11-20 04:31:55.893543 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/chunks/chunk_000002/logs/progress.log
2024-11-20 04:31:58.652109 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-11-20 04:31:58.653486 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/chunks/chunk_000003/logs/progress.log
2024-11-20 04:32:01.288772 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-11-20 04:32:01.290038 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/chunks/chunk_000004/logs/progress.log
2024-11-20 04:32:03.841432 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.043 minutes
2024-11-20 04:32:03.857005 DEBUG::tools.R/processChunks: done
2024-11-20 04:32:03.859796 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:32:03.86182 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/results/test_pe.adapter_contaminated_1.RData
2024-11-20 04:32:03.864338 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-20 04:32:03.865783 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/results/test_pe.adapter_contaminated_2.RData
2024-11-20 04:32:03.874136 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-11-20 04:32:03.87586 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/results/test_pe.summary_preprocess.tab
2024-11-20 04:32:03.878696 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/bams/processed.aligner_input_1.fastq ...
2024-11-20 04:32:03.883393 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/bams/processed.aligner_input_2.fastq ...
2024-11-20 04:32:03.887041 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/reports/shortReadReport_1 ...
2024-11-20 04:32:04.921746 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.alignReads.sparsechunks.1773221cbefc/reports/shortReadReport_2 ...
2024-11-20 04:32:05.917849 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:32:06.063885 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-11-20 04:32:06.06747 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/RtmpDq0sCN/test.alignReadsOneSingleEnd.177321cb3e99f/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-11-20 04:32:06.272422 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-11-20 04:32:06.344623 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReadsOneSingleEnd.177321cb3e99f/results/test.alignReads.summary_alignment.tab
2024-11-20 04:32:06.383042 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.alignReadsOneSingleEnd.177321cb3e99f/results/test.alignReads.summary_analyzed_bamstats.tab
2024-11-20 04:32:06.384366 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0.001 0.002 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/RtmpDq0sCN/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-11-20 04:32:06.607334 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.genotype.1773241295ccf/results/test_pe.coverage.RData
2024-11-20 04:32:06.608901 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpDq0sCN/test.genotype.1773241295ccf/results/test_pe.coverage.bw
2024-11-20 04:32:06.699802 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.genotype.1773241295ccf/results/test_pe.summary_coverage.tab
2024-11-20 04:32:06.701294 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-20 04:32:14.636723 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-20 04:32:14.706636 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-20 04:32:14.720855 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-20 04:32:14.72219 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.genotype.1773241295ccf/results/test_pe.raw_variants.RData
2024-11-20 04:32:14.724257 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.genotype.1773241295ccf/results/test_pe.filtered_variants.RData
2024-11-20 04:32:14.725422 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-20 04:32:14.726418 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-20 04:32:15.038867 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-20 04:32:15.03991 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-11-20 04:33:05.871417 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-20 04:33:06.177698 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-20 04:33:06.178418 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/RtmpDq0sCN/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-11-20 04:33:06.476476 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-20 04:33:14.377744 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-20 04:33:14.438929 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-20 04:33:14.451775 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-20 04:33:14.452803 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.1773254792fc3/results/test_pe.raw_variants.RData
2024-11-20 04:33:14.454713 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.1773254792fc3/results/test_pe.filtered_variants.RData
2024-11-20 04:33:14.455826 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:33:14.562982 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-20 04:33:22.338238 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-20 04:33:22.382416 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-20 04:33:22.395189 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-20 04:33:22.396182 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.filters.177326a83d52e/results/test_pe.raw_variants.RData
2024-11-20 04:33:22.39813 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.filters.177326a83d52e/results/test_pe.filtered_variants.RData
2024-11-20 04:33:22.399173 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-20 04:33:22.400371 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-20 04:33:30.061984 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-20 04:33:30.137987 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-20 04:33:30.15116 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-20 04:33:30.152239 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.filters.177326a83d52e/results/test_pe.raw_variants.RData
2024-11-20 04:33:30.154392 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.filters.177326a83d52e/results/test_pe.filtered_variants.RData
2024-11-20 04:33:30.15605 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:33:30.410904 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-20 04:33:30.412211 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-11-20 04:33:32.934795 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-20 04:33:32.996471 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-20 04:33:33.009447 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-20 04:33:33.010453 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.which.177324868ffcc/results/test_pe.raw_variants.RData
2024-11-20 04:33:33.011872 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.wrap.callVariants.which.177324868ffcc/results/test_pe.filtered_variants.RData
2024-11-20 04:33:33.012995 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:33:33.125922 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-20 04:33:33.126926 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:33:34.733675 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-20 04:33:34.872605 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-11-20 04:34:15.060761 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/smgoaxcq/merged/results/bla.coverage.RData
2024-11-20 04:34:15.064967 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpDq0sCN/smgoaxcq/merged/results/bla.coverage.bw
2024-11-20 04:34:15.118967 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/smgoaxcq/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-11-20 04:34:16.439113 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/ecknmbsj/merged/results/bla.coverage.RData
2024-11-20 04:34:16.440793 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpDq0sCN/ecknmbsj/merged/results/bla.coverage.bw
2024-11-20 04:34:16.450511 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/ecknmbsj/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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/RtmpDq0sCN/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-11-20 04:34:17.356778 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-11-20 04:34:17.357585 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpDq0sCN/test.detectRRNA.177326d322c07/bams/rRNA_contam/input1.fastq
2024-11-20 04:34:17.360112 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/RtmpDq0sCN/test.detectRRNA.177326d322c07/bams/rRNA_contam/test_se /tmp/RtmpDq0sCN/test.detectRRNA.177326d322c07/bams/rRNA_contam/input1.fastq 2>&1
2024-11-20 04:34:17.506926 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-11-20 04:34:17.507766 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:34:17.629193 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-11-20 04:34:17.629878 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpDq0sCN/test.detectRRNA.paired_end.17732546ef1bb/bams/rRNA_contam/input1.fastq
2024-11-20 04:34:17.631002 INFO::io.R/writeFastQFiles: writing filename= /tmp/RtmpDq0sCN/test.detectRRNA.paired_end.17732546ef1bb/bams/rRNA_contam/input2.fastq
2024-11-20 04:34:17.632664 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/RtmpDq0sCN/test.detectRRNA.paired_end.17732546ef1bb/bams/rRNA_contam/test_pe /tmp/RtmpDq0sCN/test.detectRRNA.paired_end.17732546ef1bb/bams/rRNA_contam/input1.fastq -a paired /tmp/RtmpDq0sCN/test.detectRRNA.paired_end.17732546ef1bb/bams/rRNA_contam/input2.fastq 2>&1
2024-11-20 04:34:17.850819 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-11-20 04:34:17.851795 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-11-20 04:34:17.866734 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/RtmpDq0sCN/test_get_rRNA_idsbifktrqx/test_pe /tmp/RtmpDq0sCN/test_get_rRNA_idsbifktrqx/1.fastq -a paired /tmp/RtmpDq0sCN/test_get_rRNA_idsbifktrqx/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-11-20 04:34:18.096101 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/RtmpDq0sCN/test_get_rRNAIds_randomcrexdpiq/test_pe /tmp/RtmpDq0sCN/test_get_rRNAIds_randomcrexdpiq/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-11-20 04:34:18.312008 INFO::filterQuality.R/filterQuality: filterByLength...
2024-11-20 04:34:18.313178 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-11-20 04:34:18.313836 INFO::filterQuality.R/filterByLength: done
2024-11-20 04:34:18.349554 INFO::filterQuality.R/filterQuality: filterByLength...
2024-11-20 04:34:18.35019 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-11-20 04:34:18.350825 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-11-20 04:34:18.387208 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-20 04:34:18.393719 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-20 04:34:18.394467 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-20 04:34:18.397605 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-20 04:34:18.398323 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-20 04:34:18.401444 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-11-20 04:34:18.402164 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-11-20 04:34:18.405286 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/RtmpDq0sCN/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-11-20 04:34:18.625737 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-11-20 04:34:18.627349 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/RtmpDq0sCN/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-11-20 04:34:18.736644 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-11-20 04:34:18.797956 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-20 04:34:18.800146 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-11-20 04:34:18.801708 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/RtmpDq0sCN/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-11-20 04:34:18.980573 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/RtmpDq0sCN/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-11-20 04:34:19.101765 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/RtmpDq0sCN/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-11-20 04:34:19.21287 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-11-20 04:34:19.255105 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-20 04:34:19.257161 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-11-20 04:34:19.258889 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/RtmpDq0sCN/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-11-20 04:34:19.683372 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-11-20 04:34:19.727077 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-11-20 04:34:19.729089 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-11-20 04:34:19.730757 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/RtmpDq0sCN/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/RtmpDq0sCN/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-11-20 04:34:20.342196 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-20 04:34:20.348527 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-11-20 04:34:20.351653 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-11-20 04:34:20.353739 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:34:23.210612 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:34:23.211797 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000001/logs/progress.log
2024-11-20 04:34:25.731445 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-11-20 04:34:25.732848 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000002/logs/progress.log
2024-11-20 04:34:28.238687 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-11-20 04:34:28.24031 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000003/logs/progress.log
2024-11-20 04:34:30.839403 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-11-20 04:34:30.877486 DEBUG::tools.R/processChunks: done
2024-11-20 04:34:30.879919 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:34:30.881288 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.adapter_contaminated_1.RData
2024-11-20 04:34:30.883335 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-20 04:34:30.884539 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.adapter_contaminated_2.RData
2024-11-20 04:34:30.891651 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-11-20 04:34:30.89334 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.summary_preprocess.tab
2024-11-20 04:34:30.89564 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/bams/processed.aligner_input_1.fastq ...
2024-11-20 04:34:30.900401 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/bams/processed.aligner_input_2.fastq ...
2024-11-20 04:34:30.903714 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/reports/shortReadReport_1 ...
2024-11-20 04:34:31.947124 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/reports/shortReadReport_2 ...
2024-11-20 04:34:32.683086 INFO::preprocessReads.R/preprocessReads: done
2024-11-20 04:34:32.796393 INFO::alignReads.R/alignReads: starting alignment...
2024-11-20 04:34:32.800912 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:34:35.995827 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:34:35.997503 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000001/logs/progress.log
2024-11-20 04:34:38.540013 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.042 minutes
2024-11-20 04:34:38.541576 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/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-11-20 04:34:41.117334 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-11-20 04:34:41.119284 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/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-11-20 04:34:43.681038 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-11-20 04:34:43.684083 DEBUG::tools.R/processChunks: done
2024-11-20 04:34:43.685654 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-11-20 04:34:43.84522 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-20 04:34:43.851834 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.summary_alignment.tab
2024-11-20 04:34:43.857255 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.summary_analyzed_bamstats.tab
2024-11-20 04:34:43.858645 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-20 04:34:44.040379 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.summary_target_lengths.tab
2024-11-20 04:34:44.075759 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-20 04:34:44.076498 INFO::alignReads.R/alignReads: done
2024-11-20 04:34:44.194257 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-11-20 04:34:44.214929 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:34:47.275842 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:34:47.277554 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000001/logs/progress.log
2024-11-20 04:34:49.666729 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-11-20 04:34:49.668407 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000002/logs/progress.log
2024-11-20 04:34:52.044885 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2024-11-20 04:34:52.046556 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000003/logs/progress.log
2024-11-20 04:34:54.418899 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.04 minutes
2024-11-20 04:34:54.421186 DEBUG::tools.R/processChunks: done
2024-11-20 04:34:54.422563 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-11-20 04:34:54.433167 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.counts_exon.tab
2024-11-20 04:34:54.44069 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.counts_exon_disjoint.tab
2024-11-20 04:34:54.445684 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.counts_gene.tab
2024-11-20 04:34:54.449695 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.counts_gene_coding.tab
2024-11-20 04:34:54.453576 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.counts_gene_exonic.tab
2024-11-20 04:34:54.457852 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.counts_intergenic.tab
2024-11-20 04:34:54.464401 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.counts_intron.tab
2024-11-20 04:34:54.466313 INFO::countGenomicFeatures.R/mergeCounts: done
2024-11-20 04:34:54.470744 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.summary_counts.tab
2024-11-20 04:34:54.472079 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-11-20 04:34:54.707318 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-11-20 04:34:54.708026 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-11-20 04:34:54.818202 INFO::coverage.R/calculateCoverage: starting...
2024-11-20 04:34:54.824264 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:34:57.960846 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:34:57.962562 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000001/logs/progress.log
2024-11-20 04:35:00.126149 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-11-20 04:35:00.128033 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000002/logs/progress.log
2024-11-20 04:35:02.304995 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.036 minutes
2024-11-20 04:35:02.306826 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/chunks/chunk_000003/logs/progress.log
2024-11-20 04:35:04.467633 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.036 minutes
2024-11-20 04:35:04.470295 DEBUG::tools.R/processChunks: done
2024-11-20 04:35:05.902098 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.coverage.RData
2024-11-20 04:35:05.903499 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.coverage.bw
2024-11-20 04:35:05.91398 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.summary_coverage.tab
2024-11-20 04:35:05.914991 INFO::coverage.R/calculateCoverage: done
2024-11-20 04:35:05.916806 INFO::analyzeVariants/analyzeVariants: starting ...
2024-11-20 04:35:06.033341 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-20 04:35:09.286499 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-20 04:35:09.343314 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-20 04:35:09.356145 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-20 04:35:09.357206 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.raw_variants.RData
2024-11-20 04:35:09.358522 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.filtered_variants.RData
2024-11-20 04:35:09.359575 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-20 04:35:09.360397 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-20 04:35:09.530784 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-20 04:35:09.610219 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/results/test_pe.summary_variants.tab
2024-11-20 04:35:09.612118 INFO::analyzeVariants/analyzeVariants: done
2024-11-20 04:35:09.616088 INFO::Pipeline run successful.
2024-11-20 04:35:09.792902 INFO::mergeLanes.R/doMergeLanes: starting...
2024-11-20 04:35:09.797822 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:35:09.80003 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.adapter_contaminated_1.RData
2024-11-20 04:35:09.802575 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-20 04:35:09.80444 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.adapter_contaminated_2.RData
2024-11-20 04:35:09.815039 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-11-20 04:35:09.817115 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.summary_preprocess.tab
2024-11-20 04:35:09.819042 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-11-20 04:35:10.04496 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-11-20 04:35:10.051682 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.summary_alignment.tab
2024-11-20 04:35:10.058736 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.summary_analyzed_bamstats.tab
2024-11-20 04:35:10.060639 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-11-20 04:35:10.273026 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.summary_target_lengths.tab
2024-11-20 04:35:10.313262 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-11-20 04:35:10.364063 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-11-20 04:35:10.384314 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.counts_exon.tab
2024-11-20 04:35:10.394051 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.counts_exon_disjoint.tab
2024-11-20 04:35:10.399842 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.counts_gene.tab
2024-11-20 04:35:10.40468 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.counts_gene_coding.tab
2024-11-20 04:35:10.409545 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.counts_gene_exonic.tab
2024-11-20 04:35:10.41467 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.counts_intergenic.tab
2024-11-20 04:35:10.425094 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.counts_intron.tab
2024-11-20 04:35:10.427214 INFO::countGenomicFeatures.R/mergeCounts: done
2024-11-20 04:35:10.433039 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.summary_counts.tab
2024-11-20 04:35:10.434623 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-11-20 04:35:10.626372 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-11-20 04:35:12.787904 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.coverage.RData
2024-11-20 04:35:12.790755 INFO::coverage.R/saveCoverage: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.coverage.bw
2024-11-20 04:35:12.800457 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.summary_coverage.tab
2024-11-20 04:35:12.849267 INFO::analyzeVariants/analyzeVariants: starting ...
2024-11-20 04:35:12.956259 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-11-20 04:35:15.933021 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-11-20 04:35:15.990193 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-11-20 04:35:16.002981 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-11-20 04:35:16.004009 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.raw_variants.RData
2024-11-20 04:35:16.005359 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.filtered_variants.RData
2024-11-20 04:35:16.006416 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-11-20 04:35:16.007275 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-11-20 04:35:16.177967 INFO::analyzeVariants.R/writeVCF: ...done
2024-11-20 04:35:16.255651 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.mergeLanes.1773215ae9eeb/merged/results/merged.summary_variants.tab
2024-11-20 04:35:16.257618 INFO::analyzeVariants/analyzeVariants: done
2024-11-20 04:35:16.260695 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/RtmpDq0sCN/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-11-20 04:35:16.54356 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-20 04:35:16.56134 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-11-20 04:35:16.564401 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-11-20 04:35:16.566394 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:35:19.672385 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:35:19.673544 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/chunks/chunk_000001/logs/progress.log
2024-11-20 04:35:22.254494 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-11-20 04:35:22.295539 DEBUG::tools.R/processChunks: done
2024-11-20 04:35:22.297406 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:35:22.298537 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/results/test_pe.adapter_contaminated_1.RData
2024-11-20 04:35:22.299859 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-20 04:35:22.300835 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/results/test_pe.adapter_contaminated_2.RData
2024-11-20 04:35:22.305776 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-11-20 04:35:22.307113 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/results/test_pe.summary_preprocess.tab
2024-11-20 04:35:22.308747 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/bams/processed.aligner_input_1.fastq ...
2024-11-20 04:35:22.313003 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/bams/processed.aligner_input_2.fastq ...
2024-11-20 04:35:22.317223 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/reports/shortReadReport_1 ...
2024-11-20 04:35:23.529922 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.preprocessReads.177325eff0c8c/reports/shortReadReport_2 ...
2024-11-20 04:35:24.303145 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:35:24.575715 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-20 04:35:24.582103 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-11-20 04:35:24.585441 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-11-20 04:35:24.587656 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:35:28.033478 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:35:28.034782 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/chunks/chunk_000001/logs/progress.log
2024-11-20 04:35:30.599704 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-11-20 04:35:30.601327 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/chunks/chunk_000002/logs/progress.log
2024-11-20 04:35:33.110147 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.042 minutes
2024-11-20 04:35:33.11188 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/chunks/chunk_000003/logs/progress.log
2024-11-20 04:35:35.678615 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.043 minutes
2024-11-20 04:35:35.71631 DEBUG::tools.R/processChunks: done
2024-11-20 04:35:35.718582 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:35:35.719913 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/results/test_pe.adapter_contaminated_1.RData
2024-11-20 04:35:35.721596 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-20 04:35:35.722761 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/results/test_pe.adapter_contaminated_2.RData
2024-11-20 04:35:35.729417 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-11-20 04:35:35.730904 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/results/test_pe.summary_preprocess.tab
2024-11-20 04:35:35.733102 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/bams/processed.aligner_input_1.fastq ...
2024-11-20 04:35:35.737761 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/bams/processed.aligner_input_2.fastq ...
2024-11-20 04:35:35.741019 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/reports/shortReadReport_1 ...
2024-11-20 04:35:36.802934 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.preprocessReads.minichunks.177324ddde6ef/reports/shortReadReport_2 ...
2024-11-20 04:35:37.610989 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/RtmpDq0sCN/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-11-20 04:35:37.904657 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-20 04:35:37.924986 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-11-20 04:35:37.927745 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:35:40.912649 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:35:40.913836 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/RtmpDq0sCN/test.preprocessReads_single_end.177324559ee64/chunks/chunk_000001/logs/progress.log
2024-11-20 04:35:43.267977 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2024-11-20 04:35:43.297086 DEBUG::tools.R/processChunks: done
2024-11-20 04:35:43.299523 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:35:43.301184 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads_single_end.177324559ee64/results/test_se.adapter_contaminated_1.RData
2024-11-20 04:35:43.306578 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-11-20 04:35:43.307897 INFO::io.R/saveWithID: saving file= /tmp/RtmpDq0sCN/test.preprocessReads_single_end.177324559ee64/results/test_se.summary_preprocess.tab
2024-11-20 04:35:43.309371 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/RtmpDq0sCN/test.preprocessReads_single_end.177324559ee64/bams/processed.aligner_input_1.fastq ...
2024-11-20 04:35:43.313078 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/RtmpDq0sCN/test.preprocessReads_single_end.177324559ee64/reports/shortReadReport_1 ...
2024-11-20 04:35:44.322009 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-11-20 04:35:44.828346 INFO::preprocessReads.R/preprocessReads: starting...
2024-11-20 04:35:44.851517 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-11-20 04:35:44.879499 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-11-20 04:35:44.88157 DEBUG::tools.R/processChunks: starting...
2024-11-20 04:35:48.005754 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-11-20 04:35:48.006911 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-11-20 04:35:50.681875 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.045 minutes
2024-11-20 04:35:50.714204 DEBUG::tools.R/processChunks: done
2024-11-20 04:35:50.716086 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-11-20 04:35:50.717175 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-11-20 04:35:50.718442 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-11-20 04:35:50.719429 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-11-20 04:35:50.724365 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-11-20 04:35:50.725664 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-11-20 04:35:50.727328 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-11-20 04:35:50.732586 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-11-20 04:35:50.736434 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-11-20 04:36:44.844315 DEBUG::tools.R/traceMem: wired.mem=-27.215770 GiB
2024-11-20 04:37:44.91048 DEBUG::tools.R/traceMem: wired.mem=-30.933144 GiB
2024-11-20 04:38:44.986301 DEBUG::tools.R/traceMem: wired.mem=-16.104321 GiB
2024-11-20 04:39:45.052643 DEBUG::tools.R/traceMem: wired.mem=-32.695718 GiB
2024-11-20 04:40:45.101112 DEBUG::tools.R/traceMem: wired.mem=-32.538022 GiB
2024-11-20 04:41:45.167375 DEBUG::tools.R/traceMem: wired.mem=-30.723789 GiB
2024-11-20 04:42:45.235065 DEBUG::tools.R/traceMem: wired.mem=-29.507351 GiB
2024-11-20 04:43:45.3029 DEBUG::tools.R/traceMem: wired.mem=-32.844788 GiB
2024-11-20 04:44:45.368754 DEBUG::tools.R/traceMem: wired.mem=-25.864057 GiB
2024-11-20 04:45:45.434976 DEBUG::tools.R/traceMem: wired.mem=-24.975602 GiB
2024-11-20 04:46:45.501162 DEBUG::tools.R/traceMem: wired.mem=-29.537022 GiB
2024-11-20 04:47:45.50958 DEBUG::tools.R/traceMem: wired.mem=-29.104206 GiB
2024-11-20 04:48:45.580621 DEBUG::tools.R/traceMem: wired.mem=-22.638047 GiB
2024-11-20 04:49:45.620083 DEBUG::tools.R/traceMem: wired.mem=-25.671610 GiB
2024-11-20 04:50:45.689474 DEBUG::tools.R/traceMem: wired.mem=-17.963028 GiB
2024-11-20 04:51:45.755604 DEBUG::tools.R/traceMem: wired.mem=-27.957465 GiB
2024-11-20 04:52:45.821586 DEBUG::tools.R/traceMem: wired.mem=-28.759159 GiB
2024-11-20 04:53:45.887738 DEBUG::tools.R/traceMem: wired.mem=-25.368834 GiB
2024-11-20 04:54:45.954123 DEBUG::tools.R/traceMem: wired.mem=-27.163775 GiB
2024-11-20 04:55:46.021593 DEBUG::tools.R/traceMem: wired.mem=-31.710376 GiB
2024-11-20 04:56:46.088852 DEBUG::tools.R/traceMem: wired.mem=-33.935856 GiB
2024-11-20 04:57:46.156382 DEBUG::tools.R/traceMem: wired.mem=-25.042194 GiB
2024-11-20 04:58:46.169803 DEBUG::tools.R/traceMem: wired.mem=-25.950515 GiB
2024-11-20 04:59:46.236177 DEBUG::tools.R/traceMem: wired.mem=-21.362455 GiB
2024-11-20 05:00:46.302525 DEBUG::tools.R/traceMem: wired.mem=-18.517471 GiB
2024-11-20 05:01:46.36932 DEBUG::tools.R/traceMem: wired.mem=-28.646068 GiB
2024-11-20 05:02:46.436154 DEBUG::tools.R/traceMem: wired.mem=-27.562611 GiB
2024-11-20 05:03:46.500428 DEBUG::tools.R/traceMem: wired.mem=-30.619480 GiB
2024-11-20 05:04:46.539041 DEBUG::tools.R/traceMem: wired.mem=-32.872821 GiB
2024-11-20 05:05:46.604792 DEBUG::tools.R/traceMem: wired.mem=-33.617482 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