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

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

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.
- See Martin Grigorov's blog post for how to debug Linux ARM64 related issues on a x86_64 host.

raw results

Summary

Package: HTSeqGenie

Version: 4.35.0

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

StartedAt: 2024-08-15 05:47:50 -0000 (Thu, 15 Aug 2024)

EndedAt: 2024-08-15 06:02:51 -0000 (Thu, 15 Aug 2024)

EllapsedTime: 900.6 seconds

RetCode: 0

Status: OK

CheckDir: HTSeqGenie.Rcheck

Warnings: 0

Command output

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


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

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

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

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

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

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

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

Installation output

HTSeqGenie.Rcheck/00install.out

##############################################################################
##############################################################################
###
### Running command:
###
###   /home/biocbuild/R/R/bin/R CMD INSTALL HTSeqGenie
###
##############################################################################
##############################################################################


* installing to library ‘/home/biocbuild/R/R-4.4.1/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: aarch64-unknown-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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:55:15.260259 INFO::preprocessReads.R/preprocessReads: starting...
2024-08-15 05:55:15.269223 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:55:15.274584 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-08-15 05:55:15.277274 DEBUG::tools.R/processChunks: starting...
2024-08-15 05:55:18.550418 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 05:55:18.552461 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/chunks/chunk_000001/logs/progress.log
2024-08-15 05:55:21.498206 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2024-08-15 05:55:21.500235 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/chunks/chunk_000002/logs/progress.log
2024-08-15 05:55:24.435615 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.049 minutes
2024-08-15 05:55:24.437628 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/chunks/chunk_000003/logs/progress.log
2024-08-15 05:55:27.347619 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.048 minutes
2024-08-15 05:55:27.389141 DEBUG::tools.R/processChunks: done
2024-08-15 05:55:27.394081 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 05:55:27.397244 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/results/test_pe.adapter_contaminated_1.RData
2024-08-15 05:55:27.401252 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-08-15 05:55:27.403858 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/results/test_pe.adapter_contaminated_2.RData
2024-08-15 05:55:27.416532 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-08-15 05:55:27.419853 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/results/test_pe.summary_preprocess.tab
2024-08-15 05:55:27.424298 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/bams/processed.aligner_input_1.fastq ...
2024-08-15 05:55:27.431488 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/bams/processed.aligner_input_2.fastq ...
2024-08-15 05:55:27.437183 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/reports/shortReadReport_1 ...
2024-08-15 05:55:29.327522 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/reports/shortReadReport_2 ...
2024-08-15 05:55:30.894691 INFO::preprocessReads.R/preprocessReads: done
2024-08-15 05:55:30.95329 INFO::alignReads.R/alignReads: starting alignment...
2024-08-15 05:55:30.959756 DEBUG::tools.R/processChunks: starting...
2024-08-15 05:55:35.739764 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 05:55:35.742061 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/chunks/chunk_000001/logs/progress.log
2024-08-15 05:55:38.87038 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.052 minutes
2024-08-15 05:55:38.872663 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/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-08-15 05:55:41.607307 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-08-15 05:55:41.609667 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/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-08-15 05:55:44.36793 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-08-15 05:55:44.371552 DEBUG::tools.R/processChunks: done
2024-08-15 05:55:44.373654 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-08-15 05:55:44.695053 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-08-15 05:55:44.706954 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/results/test_pe.summary_alignment.tab
2024-08-15 05:55:44.717682 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/results/test_pe.summary_analyzed_bamstats.tab
2024-08-15 05:55:44.720216 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-08-15 05:55:44.994429 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.34a76db062ab3/results/test_pe.summary_target_lengths.tab
2024-08-15 05:55:45.053773 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-08-15 05:55:45.055121 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:55:45.35765 INFO::preprocessReads.R/preprocessReads: starting...
2024-08-15 05:55:45.361205 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:55:45.440534 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2024-08-15 05:55:45.447161 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:55:45.451614 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-08-15 05:55:45.454288 DEBUG::tools.R/processChunks: starting...
2024-08-15 05:55:49.201439 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 05:55:49.203583 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/chunks/chunk_000001/logs/progress.log
2024-08-15 05:55:52.033211 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-08-15 05:55:52.035209 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/chunks/chunk_000002/logs/progress.log
2024-08-15 05:55:54.875968 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.047 minutes
2024-08-15 05:55:54.878104 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/chunks/chunk_000003/logs/progress.log
2024-08-15 05:55:57.813961 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.049 minutes
2024-08-15 05:55:57.81595 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/chunks/chunk_000004/logs/progress.log
2024-08-15 05:56:00.637007 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.047 minutes
2024-08-15 05:56:00.679715 DEBUG::tools.R/processChunks: done
2024-08-15 05:56:00.684551 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 05:56:00.687969 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/results/test_pe.adapter_contaminated_1.RData
2024-08-15 05:56:00.692447 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-08-15 05:56:00.695133 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/results/test_pe.adapter_contaminated_2.RData
2024-08-15 05:56:00.709925 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-08-15 05:56:00.713056 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/results/test_pe.summary_preprocess.tab
2024-08-15 05:56:00.717967 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/bams/processed.aligner_input_1.fastq ...
2024-08-15 05:56:00.72543 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/bams/processed.aligner_input_2.fastq ...
2024-08-15 05:56:00.731642 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/reports/shortReadReport_1 ...
2024-08-15 05:56:02.623235 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReads.sparsechunks.34a76d42ca5797/reports/shortReadReport_2 ...
2024-08-15 05:56:04.167542 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:56:04.367278 INFO::alignReads.R/alignReadsChunk: running gsnap...
2024-08-15 05:56:04.37337 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 /home/biocbuild/tmp/RtmpdMxaIg/test.alignReadsOneSingleEnd.34a76d733f7e9a/bams/test.alignReads /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2024-08-15 05:56:04.510367 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2024-08-15 05:56:04.641786 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReadsOneSingleEnd.34a76d733f7e9a/results/test.alignReads.summary_alignment.tab
2024-08-15 05:56:04.688289 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.alignReadsOneSingleEnd.34a76d733f7e9a/results/test.alignReads.summary_analyzed_bamstats.tab
2024-08-15 05:56:04.690328 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



Executing test function test.annotateVariants  ... Timing stopped at: 0 0.003 0.004
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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:56:05.095594 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.genotype.34a76d1dd9026d/results/test_pe.coverage.RData
2024-08-15 05:56:05.09799 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.genotype.34a76d1dd9026d/results/test_pe.coverage.bw
2024-08-15 05:56:05.284231 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.genotype.34a76d1dd9026d/results/test_pe.summary_coverage.tab
2024-08-15 05:56:05.286697 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 05:56:18.489638 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 05:56:18.626837 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 05:56:18.653924 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 05:56:18.656265 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.genotype.34a76d1dd9026d/results/test_pe.raw_variants.RData
2024-08-15 05:56:18.659645 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.genotype.34a76d1dd9026d/results/test_pe.filtered_variants.RData
2024-08-15 05:56:18.661802 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-08-15 05:56:18.663722 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-08-15 05:56:19.245753 INFO::analyzeVariants.R/writeVCF: ...done
2024-08-15 05:56:19.247526 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2024-08-15 05:57:44.724799 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-08-15 05:57:45.405864 INFO::analyzeVariants.R/writeVCF: ...done
2024-08-15 05:57:45.407342 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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:57:46.098678 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 05:57:59.3786 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 05:57:59.494431 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 05:57:59.519488 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 05:57:59.521373 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.34a76d37725500/results/test_pe.raw_variants.RData
2024-08-15 05:57:59.524545 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.34a76d37725500/results/test_pe.filtered_variants.RData
2024-08-15 05:57:59.526522 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:57:59.717123 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 05:58:12.672308 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 05:58:12.760918 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 05:58:12.790518 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 05:58:12.792611 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.filters.34a76d74596a1a/results/test_pe.raw_variants.RData
2024-08-15 05:58:12.795884 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.filters.34a76d74596a1a/results/test_pe.filtered_variants.RData
2024-08-15 05:58:12.797717 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-08-15 05:58:12.799862 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 05:58:26.065938 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 05:58:26.127631 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 05:58:26.154462 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 05:58:26.15658 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.filters.34a76d74596a1a/results/test_pe.raw_variants.RData
2024-08-15 05:58:26.160212 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.filters.34a76d74596a1a/results/test_pe.filtered_variants.RData
2024-08-15 05:58:26.163161 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:58:28.331816 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 05:58:28.333639 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2024-08-15 05:58:32.034508 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 05:58:32.150163 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 05:58:32.176067 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 05:58:32.177999 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.which.34a76d40fe9b42/results/test_pe.raw_variants.RData
2024-08-15 05:58:32.180378 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.wrap.callVariants.which.34a76d40fe9b42/results/test_pe.filtered_variants.RData
2024-08-15 05:58:32.182207 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:58:32.365326 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-08-15 05:58:32.367264 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:58:32.617476 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-08-15 05:58:32.935633 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-08-15 05:59:47.749568 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/xspbynql/merged/results/bla.coverage.RData
2024-08-15 05:59:47.752808 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpdMxaIg/xspbynql/merged/results/bla.coverage.bw
2024-08-15 05:59:47.865838 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/xspbynql/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2024-08-15 05:59:49.312317 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/jtahdbkm/merged/results/bla.coverage.RData
2024-08-15 05:59:49.31418 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpdMxaIg/jtahdbkm/merged/results/bla.coverage.bw
2024-08-15 05:59:49.328875 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/jtahdbkm/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.checkConfig.analyzeVariants  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.checkConfig.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:50.971832 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-08-15 05:59:50.973337 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.34a76d68892cbd/bams/rRNA_contam/input1.fastq
2024-08-15 05:59:50.977859 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 /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.34a76d68892cbd/bams/rRNA_contam/test_se /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.34a76d68892cbd/bams/rRNA_contam/input1.fastq 2>&1
2024-08-15 05:59:51.0897 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-08-15 05:59:51.091112 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:51.279238 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2024-08-15 05:59:51.280579 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.paired_end.34a76d55cb8cae/bams/rRNA_contam/input1.fastq
2024-08-15 05:59:51.282667 INFO::io.R/writeFastQFiles: writing filename= /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.paired_end.34a76d55cb8cae/bams/rRNA_contam/input2.fastq
2024-08-15 05:59:51.285955 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 /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.paired_end.34a76d55cb8cae/bams/rRNA_contam/test_pe /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.paired_end.34a76d55cb8cae/bams/rRNA_contam/input1.fastq -a paired /home/biocbuild/tmp/RtmpdMxaIg/test.detectRRNA.paired_end.34a76d55cb8cae/bams/rRNA_contam/input2.fastq 2>&1
2024-08-15 05:59:51.544677 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2024-08-15 05:59:51.546098 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2024-08-15 05:59:51.576167 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 /home/biocbuild/tmp/RtmpdMxaIg/test_get_rRNA_idssfktugqv/test_pe /home/biocbuild/tmp/RtmpdMxaIg/test_get_rRNA_idssfktugqv/1.fastq -a paired /home/biocbuild/tmp/RtmpdMxaIg/test_get_rRNA_idssfktugqv/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2024-08-15 05:59:51.871477 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 /home/biocbuild/tmp/RtmpdMxaIg/test_get_rRNAIds_randomyhgqkeap/test_pe /home/biocbuild/tmp/RtmpdMxaIg/test_get_rRNAIds_randomyhgqkeap/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2024-08-15 05:59:52.048944 INFO::filterQuality.R/filterQuality: filterByLength...
2024-08-15 05:59:52.051061 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2024-08-15 05:59:52.052457 INFO::filterQuality.R/filterByLength: done
2024-08-15 05:59:52.124604 INFO::filterQuality.R/filterQuality: filterByLength...
2024-08-15 05:59:52.125966 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2024-08-15 05:59:52.127293 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2024-08-15 05:59:52.207686 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-08-15 05:59:52.221427 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-08-15 05:59:52.223042 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-08-15 05:59:52.230179 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-08-15 05:59:52.23185 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-08-15 05:59:52.238894 INFO::preprocessReads.R/preprocessReadsChunk: done
2024-08-15 05:59:52.240556 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2024-08-15 05:59:52.247565 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.001
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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:52.672716 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:52.676558 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:52.912096 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:53.041857 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-08-15 05:59:53.046042 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:53.049651 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:53.336344 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:53.529951 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:53.731295 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:53.821999 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-08-15 05:59:53.825795 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:53.829382 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:54.097171 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:54.153313 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2024-08-15 05:59:54.156823 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:54.160121 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/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= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
 done successfully.



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 05:59:55.07942 INFO::preprocessReads.R/preprocessReads: starting...
2024-08-15 05:59:55.086279 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 05:59:55.090989 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-08-15 05:59:55.094028 DEBUG::tools.R/processChunks: starting...
2024-08-15 05:59:58.57559 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 05:59:58.58392 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000001/logs/progress.log
2024-08-15 06:00:01.387072 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-08-15 06:00:01.389134 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000002/logs/progress.log
2024-08-15 06:00:04.162161 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-08-15 06:00:04.164186 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000003/logs/progress.log
2024-08-15 06:00:06.941456 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-08-15 06:00:06.991258 DEBUG::tools.R/processChunks: done
2024-08-15 06:00:06.994978 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 06:00:06.997561 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.adapter_contaminated_1.RData
2024-08-15 06:00:07.000852 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-08-15 06:00:07.003316 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.adapter_contaminated_2.RData
2024-08-15 06:00:07.01468 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-08-15 06:00:07.017366 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.summary_preprocess.tab
2024-08-15 06:00:07.020967 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/bams/processed.aligner_input_1.fastq ...
2024-08-15 06:00:07.027575 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/bams/processed.aligner_input_2.fastq ...
2024-08-15 06:00:07.033198 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/reports/shortReadReport_1 ...
2024-08-15 06:00:08.882577 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/reports/shortReadReport_2 ...
2024-08-15 06:00:10.421754 INFO::preprocessReads.R/preprocessReads: done
2024-08-15 06:00:10.495122 INFO::alignReads.R/alignReads: starting alignment...
2024-08-15 06:00:10.499947 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:00:15.277776 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:00:15.280215 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000001/logs/progress.log
2024-08-15 06:00:17.918692 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2024-08-15 06:00:17.921006 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/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-08-15 06:00:20.552417 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2024-08-15 06:00:20.554628 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/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-08-15 06:00:23.178953 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2024-08-15 06:00:23.182508 DEBUG::tools.R/processChunks: done
2024-08-15 06:00:23.184605 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-08-15 06:00:23.489561 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-08-15 06:00:23.500143 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.summary_alignment.tab
2024-08-15 06:00:23.510041 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.summary_analyzed_bamstats.tab
2024-08-15 06:00:23.512623 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-08-15 06:00:23.760087 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.summary_target_lengths.tab
2024-08-15 06:00:23.819481 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-08-15 06:00:23.82084 INFO::alignReads.R/alignReads: done
2024-08-15 06:00:23.89552 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-08-15 06:00:23.921836 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:00:27.637671 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:00:27.640137 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000001/logs/progress.log
2024-08-15 06:00:30.1963 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-08-15 06:00:30.198544 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000002/logs/progress.log
2024-08-15 06:00:32.760382 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.043 minutes
2024-08-15 06:00:32.762619 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000003/logs/progress.log
2024-08-15 06:00:35.292849 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.042 minutes
2024-08-15 06:00:35.296137 DEBUG::tools.R/processChunks: done
2024-08-15 06:00:35.298398 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-08-15 06:00:35.315427 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.counts_exon.tab
2024-08-15 06:00:35.329041 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.counts_exon_disjoint.tab
2024-08-15 06:00:35.338087 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.counts_gene.tab
2024-08-15 06:00:35.345319 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.counts_gene_coding.tab
2024-08-15 06:00:35.352418 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.counts_gene_exonic.tab
2024-08-15 06:00:35.359689 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.counts_intergenic.tab
2024-08-15 06:00:35.371402 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.counts_intron.tab
2024-08-15 06:00:35.375082 INFO::countGenomicFeatures.R/mergeCounts: done
2024-08-15 06:00:35.382543 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.summary_counts.tab
2024-08-15 06:00:35.384888 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-08-15 06:00:35.727512 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-08-15 06:00:35.728765 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-08-15 06:00:35.801009 INFO::coverage.R/calculateCoverage: starting...
2024-08-15 06:00:35.805406 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:00:39.241253 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:00:39.243409 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000001/logs/progress.log
2024-08-15 06:00:41.43183 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.036 minutes
2024-08-15 06:00:41.433952 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000002/logs/progress.log
2024-08-15 06:00:43.633979 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2024-08-15 06:00:43.636182 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/chunks/chunk_000003/logs/progress.log
2024-08-15 06:00:45.8305 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2024-08-15 06:00:45.834048 DEBUG::tools.R/processChunks: done
2024-08-15 06:00:47.764668 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.coverage.RData
2024-08-15 06:00:47.766596 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.coverage.bw
2024-08-15 06:00:47.782882 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.summary_coverage.tab
2024-08-15 06:00:47.784768 INFO::coverage.R/calculateCoverage: done
2024-08-15 06:00:47.786846 INFO::analyzeVariants/analyzeVariants: starting ...
2024-08-15 06:00:47.861091 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 06:00:51.561725 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 06:00:51.678436 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 06:00:51.704654 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 06:00:51.706678 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.raw_variants.RData
2024-08-15 06:00:51.709249 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.filtered_variants.RData
2024-08-15 06:00:51.71126 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-08-15 06:00:51.712937 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-08-15 06:00:52.035402 INFO::analyzeVariants.R/writeVCF: ...done
2024-08-15 06:00:52.177525 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/results/test_pe.summary_variants.tab
2024-08-15 06:00:52.18029 INFO::analyzeVariants/analyzeVariants: done
2024-08-15 06:00:52.184086 INFO::Pipeline run successful.
2024-08-15 06:00:52.352845 INFO::mergeLanes.R/doMergeLanes: starting...
2024-08-15 06:00:52.35826 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 06:00:52.36119 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.adapter_contaminated_1.RData
2024-08-15 06:00:52.365 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-08-15 06:00:52.367813 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.adapter_contaminated_2.RData
2024-08-15 06:00:52.381514 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-08-15 06:00:52.384667 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.summary_preprocess.tab
2024-08-15 06:00:52.387471 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-08-15 06:00:52.709771 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-08-15 06:00:52.718866 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.summary_alignment.tab
2024-08-15 06:00:52.730058 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.summary_analyzed_bamstats.tab
2024-08-15 06:00:52.73307 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-08-15 06:00:52.986776 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.summary_target_lengths.tab
2024-08-15 06:00:53.046888 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-08-15 06:00:53.083908 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-08-15 06:00:53.106291 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.counts_exon.tab
2024-08-15 06:00:53.120507 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.counts_exon_disjoint.tab
2024-08-15 06:00:53.129452 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.counts_gene.tab
2024-08-15 06:00:53.137272 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.counts_gene_coding.tab
2024-08-15 06:00:53.144771 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.counts_gene_exonic.tab
2024-08-15 06:00:53.152911 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.counts_intergenic.tab
2024-08-15 06:00:53.167405 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.counts_intron.tab
2024-08-15 06:00:53.171409 INFO::countGenomicFeatures.R/mergeCounts: done
2024-08-15 06:00:53.18037 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.summary_counts.tab
2024-08-15 06:00:53.182901 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-08-15 06:00:53.459073 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-08-15 06:00:55.714763 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.coverage.RData
2024-08-15 06:00:55.717553 INFO::coverage.R/saveCoverage: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.coverage.bw
2024-08-15 06:00:55.732723 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.summary_coverage.tab
2024-08-15 06:00:55.769145 INFO::analyzeVariants/analyzeVariants: starting ...
2024-08-15 06:00:55.848816 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 06:01:00.488135 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 06:01:00.602326 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 06:01:00.628006 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 06:01:00.629988 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.raw_variants.RData
2024-08-15 06:01:00.63237 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.filtered_variants.RData
2024-08-15 06:01:00.634229 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-08-15 06:01:00.635734 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-08-15 06:01:00.969051 INFO::analyzeVariants.R/writeVCF: ...done
2024-08-15 06:01:01.120523 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.mergeLanes.34a76d6424e4bc/merged/results/merged.summary_variants.tab
2024-08-15 06:01:01.123231 INFO::analyzeVariants/analyzeVariants: done
2024-08-15 06:01:01.126401 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 06:01:01.437675 INFO::preprocessReads.R/preprocessReads: starting...
2024-08-15 06:01:01.459911 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 06:01:01.479827 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-08-15 06:01:01.482615 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:01:04.984254 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:01:04.986244 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/chunks/chunk_000001/logs/progress.log
2024-08-15 06:01:07.971422 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.05 minutes
2024-08-15 06:01:08.017534 DEBUG::tools.R/processChunks: done
2024-08-15 06:01:08.020491 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 06:01:08.022732 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/results/test_pe.adapter_contaminated_1.RData
2024-08-15 06:01:08.025243 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-08-15 06:01:08.027393 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/results/test_pe.adapter_contaminated_2.RData
2024-08-15 06:01:08.03598 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-08-15 06:01:08.038627 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/results/test_pe.summary_preprocess.tab
2024-08-15 06:01:08.041428 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/bams/processed.aligner_input_1.fastq ...
2024-08-15 06:01:08.047335 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/bams/processed.aligner_input_2.fastq ...
2024-08-15 06:01:08.053275 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/reports/shortReadReport_1 ...
2024-08-15 06:01:09.840192 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.34a76d763e3f51/reports/shortReadReport_2 ...
2024-08-15 06:01:11.335137 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 06:01:11.614254 INFO::preprocessReads.R/preprocessReads: starting...
2024-08-15 06:01:11.620849 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 06:01:11.625375 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_2.fastq
2024-08-15 06:01:11.628235 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:01:15.093927 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:01:15.095957 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/chunks/chunk_000001/logs/progress.log
2024-08-15 06:01:17.899557 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.047 minutes
2024-08-15 06:01:17.901559 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/chunks/chunk_000002/logs/progress.log
2024-08-15 06:01:20.690343 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2024-08-15 06:01:20.692312 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/chunks/chunk_000003/logs/progress.log
2024-08-15 06:01:23.457011 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2024-08-15 06:01:23.510869 DEBUG::tools.R/processChunks: done
2024-08-15 06:01:23.514724 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 06:01:23.517287 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/results/test_pe.adapter_contaminated_1.RData
2024-08-15 06:01:23.520784 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-08-15 06:01:23.523336 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/results/test_pe.adapter_contaminated_2.RData
2024-08-15 06:01:23.535872 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-08-15 06:01:23.538538 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/results/test_pe.summary_preprocess.tab
2024-08-15 06:01:23.542195 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/bams/processed.aligner_input_1.fastq ...
2024-08-15 06:01:23.549101 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/bams/processed.aligner_input_2.fastq ...
2024-08-15 06:01:23.555055 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/reports/shortReadReport_1 ...
2024-08-15 06:01:25.406706 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads.minichunks.34a76d470669c9/reports/shortReadReport_2 ...
2024-08-15 06:01:26.92392 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 06:01:27.200117 INFO::preprocessReads.R/preprocessReads: starting...
2024-08-15 06:01:27.221402 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/test-data/unit_tests_1.fastq
2024-08-15 06:01:27.22425 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:01:30.677901 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:01:30.679944 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads_single_end.34a76d1e9cab08/chunks/chunk_000001/logs/progress.log
2024-08-15 06:01:33.139383 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2024-08-15 06:01:33.153474 DEBUG::tools.R/processChunks: done
2024-08-15 06:01:33.156825 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 06:01:33.159297 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads_single_end.34a76d1e9cab08/results/test_se.adapter_contaminated_1.RData
2024-08-15 06:01:33.169018 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-08-15 06:01:33.171906 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads_single_end.34a76d1e9cab08/results/test_se.summary_preprocess.tab
2024-08-15 06:01:33.174853 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads_single_end.34a76d1e9cab08/bams/processed.aligner_input_1.fastq ...
2024-08-15 06:01:33.180959 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /home/biocbuild/tmp/RtmpdMxaIg/test.preprocessReads_single_end.34a76d1e9cab08/reports/shortReadReport_1 ...
2024-08-15 06:01:35.04487 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



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



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



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



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



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



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 06:01:35.771648 INFO::preprocessReads.R/preprocessReads: starting...
2024-08-15 06:01:35.794872 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2024-08-15 06:01:35.817277 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2024-08-15 06:01:35.82045 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:01:41.002758 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:01:41.004923 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-08-15 06:01:43.968592 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.049 minutes
2024-08-15 06:01:44.018247 DEBUG::tools.R/processChunks: done
2024-08-15 06:01:44.021463 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2024-08-15 06:01:44.023905 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2024-08-15 06:01:44.026524 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2024-08-15 06:01:44.028878 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2024-08-15 06:01:44.037959 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-08-15 06:01:44.040753 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2024-08-15 06:01:44.043664 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2024-08-15 06:01:44.050577 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2024-08-15 06:01:44.057179 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2024-08-15 06:01:46.109327 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2024-08-15 06:01:47.920579 INFO::preprocessReads.R/preprocessReads: done
2024-08-15 06:01:47.995954 INFO::alignReads.R/alignReads: starting alignment...
2024-08-15 06:01:48.000892 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:01:53.502124 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:01:53.504668 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1206:17367:135118" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:1304:1838:53573" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "HISEQ1:109:D093LACXX:4:2303:2956:116587" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "M" on read "HISEQ1:109:D093LACXX:4:2205:16499:6611" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1206:20028:108227" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:1207:19518:143960" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "HISEQ1:109:D093LACXX:4:2207:4065:173048" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2024-08-15 06:01:59.322963 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.097 minutes
2024-08-15 06:01:59.326148 DEBUG::tools.R/processChunks: done
2024-08-15 06:01:59.327974 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2024-08-15 06:01:59.361724 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2024-08-15 06:01:59.369539 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2024-08-15 06:01:59.376743 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2024-08-15 06:01:59.379373 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2024-08-15 06:01:59.564184 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2024-08-15 06:01:59.62059 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2024-08-15 06:01:59.621851 INFO::alignReads.R/alignReads: done
2024-08-15 06:01:59.696246 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2024-08-15 06:01:59.713731 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:02:03.176392 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:02:03.178437 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-08-15 06:02:05.775578 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2024-08-15 06:02:05.778866 DEBUG::tools.R/processChunks: done
2024-08-15 06:02:05.781515 INFO::countGenomicFeatures.R/mergeCounts: starting...
2024-08-15 06:02:05.793445 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2024-08-15 06:02:05.803686 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2024-08-15 06:02:05.811217 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2024-08-15 06:02:05.816651 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2024-08-15 06:02:05.822109 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2024-08-15 06:02:05.827777 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2024-08-15 06:02:05.835825 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2024-08-15 06:02:05.839952 INFO::countGenomicFeatures.R/mergeCounts: done
2024-08-15 06:02:05.844912 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2024-08-15 06:02:05.847293 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2024-08-15 06:02:06.118274 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2024-08-15 06:02:06.119564 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2024-08-15 06:02:06.193423 INFO::coverage.R/calculateCoverage: starting...
2024-08-15 06:02:06.197882 DEBUG::tools.R/processChunks: starting...
2024-08-15 06:02:11.954714 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2024-08-15 06:02:11.957465 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2024-08-15 06:02:14.339211 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.04 minutes
2024-08-15 06:02:14.342404 DEBUG::tools.R/processChunks: done
2024-08-15 06:02:16.076699 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2024-08-15 06:02:16.078641 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2024-08-15 06:02:16.180284 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2024-08-15 06:02:16.182075 INFO::coverage.R/calculateCoverage: done
2024-08-15 06:02:16.183733 INFO::analyzeVariants/analyzeVariants: starting ...
2024-08-15 06:02:16.260388 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2024-08-15 06:02:29.934215 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2024-08-15 06:02:30.092047 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2024-08-15 06:02:30.126517 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2024-08-15 06:02:30.129202 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2024-08-15 06:02:30.133144 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2024-08-15 06:02:30.135615 INFO::analyzeVariants.R/wrap.callVariants: ...done
2024-08-15 06:02:30.137636 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2024-08-15 06:02:30.615959 INFO::analyzeVariants.R/writeVCF: ...done
2024-08-15 06:02:30.841733 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2024-08-15 06:02:30.846699 INFO::analyzeVariants/analyzeVariants: done
2024-08-15 06:02:30.855011 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //home/biocbuild/tmp/RtmpdMxaIg/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/config/default-config.txt 
2024-08-15 06:02:31.133949 INFO::io.R/saveWithID: saving file= /home/biocbuild/tmp/RtmpdMxaIg/test.calcTargetLengths.34a76d4a9ad78a/results/test_pe.summary_target_lengths.tab
 done successfully.



Executing test function test.sclapply  ...  done successfully.



Executing test function test.tryKeepTraceback  ...  done successfully.



Executing test function test.truncateReads  ...  done successfully.



Executing test function test.truncateReads.trim5  ...  done successfully.

RUNIT TEST PROTOCOL -- Thu Aug 15 06:02:45 2024 
*********************************************** 
Number of test functions: 61 
Number of deactivated test functions: 10 
Number of errors: 0 
Number of failures: 0 

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



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (31.46 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (19.11 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.52 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (101.21 seconds)
test.wrap.callVariants: (4 checks) ... OK (13.62 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (26.63 seconds)
test.wrap.callVariants.which: (1 checks) ... OK (6.02 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.18 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.71 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (36.2 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (35.65 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.97 seconds)
test.isSparse: (5 checks) ... OK (0.14 seconds)
test.mergeCoverage: (1 checks) ... OK (1.83 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.49 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.2 seconds)
test.findTemplate: (5 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.41 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.47 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.05 seconds)
test.isAdapter: (5 checks) ... OK (0.17 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.11 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.3 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.45 seconds)
test.getRRNAIds: (1 checks) ... OK (0.29 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.2 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.09 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.07 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.gatk.R 
test.callVariantsGATK : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.callVariantsGATK.withFiltering : DEACTIVATED, callVariantsGATK() tests need gatk.path option set
test.checkGATKJar : DEACTIVATED, checkGATKJar() test needs gatk.path option set
test.excludeVariantsByRegion: (3 checks) ... OK (0.22 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.25 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.43 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.19 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.22 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.69 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.17 seconds)
test.getObjectFilename: (4 checks) ... OK (0.01 seconds)
test.safeUnlink: (2 checks) ... OK (0.01 seconds)
test.writeAudit: (0 checks) ... OK (0.21 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (66.48 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.picard.R 
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (10.18 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (15.59 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (8.12 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.12 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.12 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0 seconds)
test.plotDF: (3 checks) ... OK (0.14 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.05 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (55.37 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.28 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (14.35 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/R/R-4.4.1/site-library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.07 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.23 seconds) 

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

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

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