Back to Multiple platform build/check report for BioC 3.17
ABCDEFG[H]IJKLMNOPQRSTUVWXYZ

This page was generated on 2022-12-01 11:06:20 -0500 (Thu, 01 Dec 2022).

HostnameOSArch (*)R versionInstalled pkgs
nebbiolo1Linux (Ubuntu 22.04.1 LTS)x86_64R Under development (unstable) (2022-10-25 r83175) -- "Unsuffered Consequences" 4462
palomino3Windows Server 2022 Datacenterx64R Under development (unstable) (2022-10-11 r83083 ucrt) -- "Unsuffered Consequences" 4203
merida1macOS 10.14.6 Mojavex86_64R Under development (unstable) (2022-11-13 r83342) -- "Unsuffered Consequences" 4231
Click on any hostname to see more info about the system (e.g. compilers)      (*) as reported by 'uname -p', except on Windows and Mac OS X

CHECK results for HTSeqGenie on nebbiolo1


To the developers/maintainers of the HTSeqGenie package:
- Please 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 How and When does the builder pull? When will my changes propagate? for more information.
- Make sure to use the following settings in order to reproduce any error or warning you see on this page.

raw results

Package 914/2154HostnameOS / ArchINSTALLBUILDCHECKBUILD BIN
HTSeqGenie 4.29.0  (landing page)
Jens Reeder
Snapshot Date: 2022-11-30 14:00:15 -0500 (Wed, 30 Nov 2022)
git_url: https://git.bioconductor.org/packages/HTSeqGenie
git_branch: master
git_last_commit: 84dba93
git_last_commit_date: 2022-11-01 11:07:30 -0500 (Tue, 01 Nov 2022)
nebbiolo1Linux (Ubuntu 22.04.1 LTS) / x86_64  OK    OK    ERROR  
palomino3Windows Server 2022 Datacenter / x64... NOT SUPPORTED ...
merida1macOS 10.14.6 Mojave / x86_64... NOT SUPPORTED ...

Summary

Package: HTSeqGenie
Version: 4.29.0
Command: /home/biocbuild/bbs-3.17-bioc/R/bin/R CMD check --install=check:HTSeqGenie.install-out.txt --library=/home/biocbuild/bbs-3.17-bioc/R/library --timings HTSeqGenie_4.29.0.tar.gz
StartedAt: 2022-11-30 21:06:06 -0500 (Wed, 30 Nov 2022)
EndedAt: 2022-11-30 21:21:18 -0500 (Wed, 30 Nov 2022)
EllapsedTime: 911.9 seconds
RetCode: 1
Status:   ERROR  
CheckDir: HTSeqGenie.Rcheck
Warnings: NA

Command output

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


* using log directory ‘/home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck’
* using R Under development (unstable) (2022-10-25 r83175)
* using platform: x86_64-pc-linux-gnu (64-bit)
* using session charset: UTF-8
* checking for file ‘HTSeqGenie/DESCRIPTION’ ... OK
* checking extension type ... Package
* this is package ‘HTSeqGenie’ version ‘4.29.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 R 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 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 ... OK
* 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 ... OK
* 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’
 ERROR
Running the tests in ‘tests/doRUnit.R’ failed.
Last 13 lines of output:
  test.calculateTargetLength: (4 checks) ... OK (0.3 seconds)
  --------------------------- 
  Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.tools.R 
  test.sclapply: (10 checks) ... OK (15.8 seconds)
  test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
  --------------------------- 
  Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.trimReads.R 
  test.truncateReads: (7 checks) ... OK (0.06 seconds)
  test.truncateReads.trim5: (15 checks) ... OK (0.15 seconds) 
  
  Error in eval(ei, envir) : 
    runTests.R: failed to run unit tests, see /home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck/tests/HTSeqGenie-runit.txt for details
  Calls: source -> withVisible -> eval -> eval
  In addition: There were 50 or more warnings (use warnings() to see the first 50)
  Execution halted
* checking for unstated dependencies in vignettes ... OK
* checking package vignettes in ‘inst/doc’ ... OK
* checking running R code from vignettes ...
  ‘HTSeqGenie.Rnw’... OK
 OK
* checking re-building of vignette outputs ... OK
* checking PDF version of manual ... OK
* DONE

Status: 1 ERROR, 5 NOTEs
See
  ‘/home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck/00check.log’
for details.


Installation output

HTSeqGenie.Rcheck/00install.out

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


* installing to library ‘/home/biocbuild/bbs-3.17-bioc/R/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.fail


R Under development (unstable) (2022-10-25 r83175) -- "Unsuffered Consequences"
Copyright (C) 2022 The R Foundation for Statistical Computing
Platform: x86_64-pc-linux-gnu (64-bit)

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, sort, table,
    tapply, union, unique, unsplit, which.max, which.min

Loading required package: S4Vectors
Loading required package: stats4

Attaching package: 'S4Vectors'

The following objects are masked from 'package:base':

    I, expand.grid, unname

Loading required package: IRanges
Loading required package: GenomicRanges
Loading required package: Rsamtools
Loading required package: Biostrings
Loading required package: XVector

Attaching package: 'Biostrings'

The following object is masked from 'package:base':

    strsplit

Loading required package: ShortRead
Loading required package: BiocParallel
Loading required package: GenomicAlignments
Loading required package: SummarizedExperiment
Loading required package: MatrixGenerics
Loading required package: matrixStats

Attaching package: 'MatrixGenerics'

The following objects are masked from 'package:matrixStats':

    colAlls, colAnyNAs, colAnys, colAvgsPerRowSet, colCollapse,
    colCounts, colCummaxs, colCummins, colCumprods, colCumsums,
    colDiffs, colIQRDiffs, colIQRs, colLogSumExps, colMadDiffs,
    colMads, colMaxs, colMeans2, colMedians, colMins, colOrderStats,
    colProds, colQuantiles, colRanges, colRanks, colSdDiffs, colSds,
    colSums2, colTabulates, colVarDiffs, colVars, colWeightedMads,
    colWeightedMeans, colWeightedMedians, colWeightedSds,
    colWeightedVars, rowAlls, rowAnyNAs, rowAnys, rowAvgsPerColSet,
    rowCollapse, rowCounts, rowCummaxs, rowCummins, rowCumprods,
    rowCumsums, rowDiffs, rowIQRDiffs, rowIQRs, rowLogSumExps,
    rowMadDiffs, rowMads, rowMaxs, rowMeans2, rowMedians, rowMins,
    rowOrderStats, rowProds, rowQuantiles, rowRanges, rowRanks,
    rowSdDiffs, rowSds, rowSums2, rowTabulates, rowVarDiffs, rowVars,
    rowWeightedMads, rowWeightedMeans, rowWeightedMedians,
    rowWeightedSds, rowWeightedVars

Loading required package: Biobase
Welcome to Bioconductor

    Vignettes contain introductory material; view with
    'browseVignettes()'. To cite Bioconductor, see
    'citation("Biobase")', and for packages 'citation("pkgname")'.


Attaching package: 'Biobase'

The following object is masked from 'package:MatrixGenerics':

    rowMedians

The following objects are masked from 'package:matrixStats':

    anyMissing, rowMedians

Loading required package: VariantAnnotation

Attaching package: 'VariantAnnotation'

The following object is masked from 'package:base':

    tabulate

> 
> source(getPackageFile("unitTests/runTests.R"))
Loading required package: GenomicFeatures
Loading required package: AnnotationDbi
did not source anything in dirname= ./R 


Executing test function test.alignReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:11:26.207942 INFO::preprocessReads.R/preprocessReads: starting...
2022-11-30 21:11:26.216576 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:11:26.220317 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2022-11-30 21:11:26.222667 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:11:29.064114 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:11:29.065641 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/chunks/chunk_000001/logs/progress.log
2022-11-30 21:11:31.827057 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2022-11-30 21:11:31.828653 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/chunks/chunk_000002/logs/progress.log
2022-11-30 21:11:34.592836 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2022-11-30 21:11:34.594486 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/chunks/chunk_000003/logs/progress.log
2022-11-30 21:11:37.365395 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2022-11-30 21:11:37.418499 DEBUG::tools.R/processChunks: done
2022-11-30 21:11:37.422799 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:11:37.425172 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/results/test_pe.adapter_contaminated_1.RData
2022-11-30 21:11:37.427963 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2022-11-30 21:11:37.429638 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/results/test_pe.adapter_contaminated_2.RData
2022-11-30 21:11:37.439172 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
2022-11-30 21:11:37.441434 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/results/test_pe.summary_preprocess.tab
2022-11-30 21:11:37.444833 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/bams/processed.aligner_input_1.fastq ...
2022-11-30 21:11:37.449194 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/bams/processed.aligner_input_2.fastq ...
2022-11-30 21:11:37.45254 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/reports/shortReadReport_1 ...
2022-11-30 21:11:38.759253 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/reports/shortReadReport_2 ...
2022-11-30 21:11:39.756458 INFO::preprocessReads.R/preprocessReads: done
2022-11-30 21:11:39.804904 INFO::alignReads.R/alignReads: starting alignment...
2022-11-30 21:11:39.810901 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:11:42.483319 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:11:42.485061 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/chunks/chunk_000001/logs/progress.log
2022-11-30 21:11:45.347599 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2022-11-30 21:11:45.350414 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/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.
2022-11-30 21:11:48.01022 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2022-11-30 21:11:48.012106 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/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.
2022-11-30 21:11:50.648233 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2022-11-30 21:11:50.651762 DEBUG::tools.R/processChunks: done
2022-11-30 21:11:50.653704 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2022-11-30 21:11:50.919502 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2022-11-30 21:11:50.928026 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/results/test_pe.summary_alignment.tab
2022-11-30 21:11:50.935107 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/results/test_pe.summary_analyzed_bamstats.tab
2022-11-30 21:11:50.93683 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2022-11-30 21:11:51.177565 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.3b2ad7764df42d/results/test_pe.summary_target_lengths.tab
2022-11-30 21:11:51.2244 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2022-11-30 21:11:51.225583 INFO::alignReads.R/alignReads: done
 done successfully.



Executing test function test.alignReads.sparsechunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:11:51.505207 INFO::preprocessReads.R/preprocessReads: starting...
2022-11-30 21:11:51.509082 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:11:51.605284 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 2 , totnbreads= 26 )
2022-11-30 21:11:51.611431 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:11:51.615301 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2022-11-30 21:11:51.617776 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:11:54.866334 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:11:54.867979 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/chunks/chunk_000001/logs/progress.log
2022-11-30 21:11:57.616929 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2022-11-30 21:11:57.621396 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/chunks/chunk_000002/logs/progress.log
2022-11-30 21:12:00.391599 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.046 minutes
2022-11-30 21:12:00.393259 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/chunks/chunk_000003/logs/progress.log
2022-11-30 21:12:03.179429 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.046 minutes
2022-11-30 21:12:03.181005 DEBUG::tools.R/processChunks: starting chunkid= 4 ; see logfile= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/chunks/chunk_000004/logs/progress.log
2022-11-30 21:12:05.886765 DEBUG::tools.R/processChunks: done with chunkid= 4 ; elapsed.time= 0.045 minutes
2022-11-30 21:12:05.928173 DEBUG::tools.R/processChunks: done
2022-11-30 21:12:05.932399 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:12:05.935919 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/results/test_pe.adapter_contaminated_1.RData
2022-11-30 21:12:05.939817 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2022-11-30 21:12:05.941942 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/results/test_pe.adapter_contaminated_2.RData
2022-11-30 21:12:05.954284 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
2022-11-30 21:12:05.956965 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/results/test_pe.summary_preprocess.tab
2022-11-30 21:12:05.96141 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/bams/processed.aligner_input_1.fastq ...
2022-11-30 21:12:05.967791 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/bams/processed.aligner_input_2.fastq ...
2022-11-30 21:12:05.971611 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/reports/shortReadReport_1 ...
2022-11-30 21:12:07.393802 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.alignReads.sparsechunks.3b2ad7193a2573/reports/shortReadReport_2 ...
2022-11-30 21:12:08.562572 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.alignReadsOneSingleEnd  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:12:08.792664 INFO::alignReads.R/alignReadsChunk: running gsnap...
2022-11-30 21:12:08.797645 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -D /home/biocbuild/.local/share/gmap -t 1 -d TP53_demo_3.2.2 --quality-protocol=illumina  -A sam --read-group-id=test_se -m 0 --split-output /tmp/Rtmpl0lppe/test.alignReadsOneSingleEnd.3b2ad77daeb592/bams/test.alignReads /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq 2>&1
2022-11-30 21:12:09.020925 INFO::alignReads.R/createSummaryAlignment: counting unique bam reads...
2022-11-30 21:12:09.122059 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReadsOneSingleEnd.3b2ad77daeb592/results/test.alignReads.summary_alignment.tab
2022-11-30 21:12:09.165811 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.alignReadsOneSingleEnd.3b2ad77daeb592/results/test.alignReads.summary_analyzed_bamstats.tab
2022-11-30 21:12:09.167578 INFO::alignReads.R/alignReadsChunk: done
 done successfully.



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



Executing test function test.callVariantsVariantTools.genotype  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:12:09.504448 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.genotype.3b2ad73ca105fb/results/test_pe.coverage.RData
2022-11-30 21:12:09.506479 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpl0lppe/test.genotype.3b2ad73ca105fb/results/test_pe.coverage.bw
2022-11-30 21:12:09.621487 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.genotype.3b2ad73ca105fb/results/test_pe.summary_coverage.tab
2022-11-30 21:12:09.623525 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:12:19.681785 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:12:19.764709 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:12:19.780689 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:12:19.782204 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.genotype.3b2ad73ca105fb/results/test_pe.raw_variants.RData
2022-11-30 21:12:19.784591 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.genotype.3b2ad73ca105fb/results/test_pe.filtered_variants.RData
2022-11-30 21:12:19.78591 INFO::analyzeVariants.R/wrap.callVariants: ...done
2022-11-30 21:12:19.787071 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2022-11-30 21:12:20.206158 INFO::analyzeVariants.R/writeVCF: ...done
2022-11-30 21:12:20.207501 INFO::analyzeVariants.R/.callGenotypes: calling genotypes...
2022-11-30 21:13:07.183999 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2022-11-30 21:13:07.598894 INFO::analyzeVariants.R/writeVCF: ...done
2022-11-30 21:13:07.599945 INFO::analyzeVariants.R/.callGenotypes: done
[W::bcf_hdr_check_sanity] PL should be declared as Number=G
 done successfully.



Executing test function test.wrap.callVariants  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:13:08.077873 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:13:17.582295 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:13:17.656059 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:13:17.672622 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:13:17.674047 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.3b2ad758f236f/results/test_pe.raw_variants.RData
2022-11-30 21:13:17.676336 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.3b2ad758f236f/results/test_pe.filtered_variants.RData
2022-11-30 21:13:17.677582 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.filters  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:13:17.836254 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:13:27.111682 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:13:27.165176 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:13:27.180994 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:13:27.182258 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.filters.3b2ad7cdecf2f/results/test_pe.raw_variants.RData
2022-11-30 21:13:27.18447 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.filters.3b2ad7cdecf2f/results/test_pe.filtered_variants.RData
2022-11-30 21:13:27.185597 INFO::analyzeVariants.R/wrap.callVariants: ...done
2022-11-30 21:13:27.186872 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:13:36.550781 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:13:36.587629 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:13:36.603592 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:13:36.604951 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.filters.3b2ad7cdecf2f/results/test_pe.raw_variants.RData
2022-11-30 21:13:36.607473 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.filters.3b2ad7cdecf2f/results/test_pe.filtered_variants.RData
2022-11-30 21:13:36.609425 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.wrap.callVariants.parallel  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:13:36.757693 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
Timing stopped at: 1.439 0.492 1.722
Error in manager$availability[[as.character(result$node)]] <- TRUE : 
  wrong args for environment subassignment
In addition: There were 35 warnings (use warnings() to see them)
 done successfully.



Executing test function test.wrap.callVariants.which  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:13:38.572821 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:13:38.574716 INFO::analyzeVariants.R/buildTallyParam: restricting variant calls using 'which'
2022-11-30 21:13:41.32727 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:13:41.396403 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:13:41.411935 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:13:41.413124 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.which.3b2ad7429ea6da/results/test_pe.raw_variants.RData
2022-11-30 21:13:41.414594 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.wrap.callVariants.which.3b2ad7429ea6da/results/test_pe.filtered_variants.RData
2022-11-30 21:13:41.415799 INFO::analyzeVariants.R/wrap.callVariants: ...done
 done successfully.



Executing test function test.writeVCF.NULL  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:13:41.569856 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2022-11-30 21:13:41.57106 INFO::analyzeVariants.R/writeVCF: ...done
 done successfully.



Executing test function test.writeVCF.vcfStat  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:13:41.758309 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2022-11-30 21:13:41.963025 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  ... 2022-11-30 21:14:35.618207 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/yjgvwudr/merged/results/bla.coverage.RData
2022-11-30 21:14:35.620803 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpl0lppe/yjgvwudr/merged/results/bla.coverage.bw
2022-11-30 21:14:35.693968 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/yjgvwudr/merged/results/bla.summary_coverage.tab
 done successfully.



Executing test function test.mergeCoverage.sparse  ... 2022-11-30 21:14:36.879499 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/ltqnkoig/merged/results/bla.coverage.RData
2022-11-30 21:14:36.881752 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpl0lppe/ltqnkoig/merged/results/bla.coverage.bw
2022-11-30 21:14:36.893628 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/ltqnkoig/merged/results/bla.summary_coverage.tab
 done successfully.



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



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



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



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



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



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



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



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



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



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



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



Executing test function test.detectRRNA  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:38.300321 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2022-11-30 21:14:38.301535 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpl0lppe/test.detectRRNA.3b2ad76843ddf1/bams/rRNA_contam/input1.fastq
2022-11-30 21:14:38.304864 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmpl0lppe/test.detectRRNA.3b2ad76843ddf1/bams/rRNA_contam/test_se /tmp/Rtmpl0lppe/test.detectRRNA.3b2ad76843ddf1/bams/rRNA_contam/input1.fastq 2>&1
2022-11-30 21:14:38.508991 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2022-11-30 21:14:38.510044 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.detectRRNA.paired_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:38.691859 INFO::detectRRNA.R/detectRRNA: searching for rRNA contamination...
2022-11-30 21:14:38.692923 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpl0lppe/test.detectRRNA.paired_end.3b2ad72f89833f/bams/rRNA_contam/input1.fastq
2022-11-30 21:14:38.694577 INFO::io.R/writeFastQFiles: writing filename= /tmp/Rtmpl0lppe/test.detectRRNA.paired_end.3b2ad72f89833f/bams/rRNA_contam/input2.fastq
2022-11-30 21:14:38.696769 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmpl0lppe/test.detectRRNA.paired_end.3b2ad72f89833f/bams/rRNA_contam/test_pe /tmp/Rtmpl0lppe/test.detectRRNA.paired_end.3b2ad72f89833f/bams/rRNA_contam/input1.fastq -a paired /tmp/Rtmpl0lppe/test.detectRRNA.paired_end.3b2ad72f89833f/bams/rRNA_contam/input2.fastq 2>&1
2022-11-30 21:14:38.978083 INFO::detectRRNA.R/detectRRNA: contaminated fraction= 1
2022-11-30 21:14:38.979106 INFO::detectRRNA.R/detectRRNA: done
 done successfully.



Executing test function test.getRRNAIds  ... 2022-11-30 21:14:38.997551 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmpl0lppe/test_get_rRNA_idsibvamedo/test_pe /tmp/Rtmpl0lppe/test_get_rRNA_idsibvamedo/1.fastq -a paired /tmp/Rtmpl0lppe/test_get_rRNA_idsibvamedo/2.fastq 2>&1
 done successfully.



Executing test function test.getRRNAIds_random  ... 2022-11-30 21:14:39.300011 INFO::alignReads.R/alignReadsChunk: calling gsnap (from gmapR) with args= -t 0 -D /home/biocbuild/.local/share/gmap -n 1 -d TP53_demo_3.2.2 -A sam -B 2 --pairmax-rna=200000 --split-output /tmp/Rtmpl0lppe/test_get_rRNAIds_randomrdlqnfwv/test_pe /tmp/Rtmpl0lppe/test_get_rRNAIds_randomrdlqnfwv/1.fastq 2>&1
 done successfully.



Executing test function test.filterByLength  ... 2022-11-30 21:14:39.532828 INFO::filterQuality.R/filterQuality: filterByLength...
2022-11-30 21:14:39.534388 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 0.5
2022-11-30 21:14:39.53533 INFO::filterQuality.R/filterByLength: done
2022-11-30 21:14:39.582841 INFO::filterQuality.R/filterQuality: filterByLength...
2022-11-30 21:14:39.583887 INFO::filterQuality.R/filterByLength: fraction of filtered short reads= 1
2022-11-30 21:14:39.584778 INFO::filterQuality.R/filterByLength: done
 done successfully.



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



Executing test function test.trimTailsByQuality  ... 2022-11-30 21:14:39.634828 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2022-11-30 21:14:39.64381 INFO::preprocessReads.R/preprocessReadsChunk: done
2022-11-30 21:14:39.644942 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2022-11-30 21:14:39.64951 INFO::preprocessReads.R/preprocessReadsChunk: done
2022-11-30 21:14:39.650611 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2022-11-30 21:14:39.655072 INFO::preprocessReads.R/preprocessReadsChunk: done
2022-11-30 21:14:39.656045 INFO::preprocessReads.R/preprocessReadsChunk: Starting trimTailsByQuality ...
2022-11-30 21:14:39.660419 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 42 warnings (use warnings() to see them)
 done successfully.



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



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



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



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



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



Executing test function test.realignIndelsGATK  ... Timing stopped at: 0 0 0.001
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.001 0 0
Error in DEACTIVATED("realignIndelsGATK() tests need gatk.path option set") : 
  realignIndelsGATK() tests need gatk.path option set
 done successfully.



Executing test function test_zipUp  ...  done successfully.



Executing test function test.FastQStreamer.getReads.pefq  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:39.975874 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:39.978243 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.pefq.subsample  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:40.184466 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:40.305156 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2022-11-30 21:14:40.30814 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:40.310421 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



Executing test function test.FastQStreamer.getReads.segz  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:40.580716 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/reads.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.getReads.truncated  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:40.801497 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/truncated.fastq.gz
 done successfully.



Executing test function test.FastQStreamer.subsampler.isdeterministic  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:41.019077 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:41.095956 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2022-11-30 21:14:41.098542 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:41.100834 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:41.344478 INFO::io.R/FastQStreamer.init: counting number of reads in file= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:41.400871 INFO::io.R/FastQStreamer.init: subsampling_filter set (subsampled reads= 17 , totnbreads= 26 )
2022-11-30 21:14:41.403398 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:41.405627 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
 done successfully.



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



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



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



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



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



Executing test function test.mergeLanes  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:14:42.30387 INFO::preprocessReads.R/preprocessReads: starting...
2022-11-30 21:14:42.310602 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:14:42.314461 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2022-11-30 21:14:42.317182 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:14:45.451503 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:14:45.453223 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000001/logs/progress.log
2022-11-30 21:14:48.091575 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2022-11-30 21:14:48.093297 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000002/logs/progress.log
2022-11-30 21:14:50.816106 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.045 minutes
2022-11-30 21:14:50.818472 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000003/logs/progress.log
2022-11-30 21:14:53.461083 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2022-11-30 21:14:53.511011 DEBUG::tools.R/processChunks: done
2022-11-30 21:14:53.514927 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:14:53.517007 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.adapter_contaminated_1.RData
2022-11-30 21:14:53.519429 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2022-11-30 21:14:53.521146 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.adapter_contaminated_2.RData
2022-11-30 21:14:53.530727 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
2022-11-30 21:14:53.532672 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.summary_preprocess.tab
2022-11-30 21:14:53.53533 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/bams/processed.aligner_input_1.fastq ...
2022-11-30 21:14:53.540092 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/bams/processed.aligner_input_2.fastq ...
2022-11-30 21:14:53.544079 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/reports/shortReadReport_1 ...
2022-11-30 21:14:54.864012 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/reports/shortReadReport_2 ...
2022-11-30 21:14:55.899314 INFO::preprocessReads.R/preprocessReads: done
2022-11-30 21:14:56.021591 INFO::alignReads.R/alignReads: starting alignment...
2022-11-30 21:14:56.026749 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:14:59.110575 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:14:59.113338 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000001/logs/progress.log
2022-11-30 21:15:01.75953 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.044 minutes
2022-11-30 21:15:01.761353 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/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.
2022-11-30 21:15:04.414851 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.044 minutes
2022-11-30 21:15:04.416719 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/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.
2022-11-30 21:15:07.053623 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.044 minutes
2022-11-30 21:15:07.057691 DEBUG::tools.R/processChunks: done
2022-11-30 21:15:07.060123 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2022-11-30 21:15:07.325669 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2022-11-30 21:15:07.335414 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.summary_alignment.tab
2022-11-30 21:15:07.343714 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.summary_analyzed_bamstats.tab
2022-11-30 21:15:07.345918 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2022-11-30 21:15:07.573258 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.summary_target_lengths.tab
2022-11-30 21:15:07.619235 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2022-11-30 21:15:07.620368 INFO::alignReads.R/alignReads: done
2022-11-30 21:15:07.743694 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2022-11-30 21:15:07.763547 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:15:10.836251 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:15:10.838125 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000001/logs/progress.log
2022-11-30 21:15:13.289654 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.041 minutes
2022-11-30 21:15:13.292057 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000002/logs/progress.log
2022-11-30 21:15:15.719291 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.04 minutes
2022-11-30 21:15:15.721802 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000003/logs/progress.log
2022-11-30 21:15:18.138464 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.04 minutes
2022-11-30 21:15:18.1421 DEBUG::tools.R/processChunks: done
2022-11-30 21:15:18.14449 INFO::countGenomicFeatures.R/mergeCounts: starting...
2022-11-30 21:15:18.165917 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.counts_exon.tab
2022-11-30 21:15:18.186105 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.counts_exon_disjoint.tab
2022-11-30 21:15:18.19744 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.counts_gene.tab
2022-11-30 21:15:18.204863 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.counts_gene_coding.tab
2022-11-30 21:15:18.212724 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.counts_gene_exonic.tab
2022-11-30 21:15:18.220512 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.counts_intergenic.tab
2022-11-30 21:15:18.233915 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.counts_intron.tab
2022-11-30 21:15:18.239671 INFO::countGenomicFeatures.R/mergeCounts: done
2022-11-30 21:15:18.248098 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.summary_counts.tab
2022-11-30 21:15:18.250643 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2022-11-30 21:15:18.551602 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2022-11-30 21:15:18.552572 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2022-11-30 21:15:18.635131 INFO::coverage.R/calculateCoverage: starting...
2022-11-30 21:15:18.639992 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:15:21.934526 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:15:21.936463 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000001/logs/progress.log
2022-11-30 21:15:24.166239 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.037 minutes
2022-11-30 21:15:24.168884 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000002/logs/progress.log
2022-11-30 21:15:26.370339 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.037 minutes
2022-11-30 21:15:26.372163 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/chunks/chunk_000003/logs/progress.log
2022-11-30 21:15:28.57197 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.037 minutes
2022-11-30 21:15:28.576119 DEBUG::tools.R/processChunks: done
2022-11-30 21:15:30.335845 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.coverage.RData
2022-11-30 21:15:30.337537 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.coverage.bw
2022-11-30 21:15:30.349311 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.summary_coverage.tab
2022-11-30 21:15:30.350647 INFO::coverage.R/calculateCoverage: done
2022-11-30 21:15:30.353147 INFO::analyzeVariants/analyzeVariants: starting ...
2022-11-30 21:15:30.450988 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:15:33.248018 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:15:33.31126 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:15:33.325163 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:15:33.326346 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.raw_variants.RData
2022-11-30 21:15:33.327779 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.filtered_variants.RData
2022-11-30 21:15:33.328839 INFO::analyzeVariants.R/wrap.callVariants: ...done
2022-11-30 21:15:33.329679 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2022-11-30 21:15:33.520778 INFO::analyzeVariants.R/writeVCF: ...done
2022-11-30 21:15:33.610191 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/results/test_pe.summary_variants.tab
2022-11-30 21:15:33.612175 INFO::analyzeVariants/analyzeVariants: done
2022-11-30 21:15:33.615872 INFO::Pipeline run successful.
2022-11-30 21:15:33.805556 INFO::mergeLanes.R/doMergeLanes: starting...
2022-11-30 21:15:33.810944 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:15:33.813382 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.adapter_contaminated_1.RData
2022-11-30 21:15:33.816639 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2022-11-30 21:15:33.818825 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.adapter_contaminated_2.RData
2022-11-30 21:15:33.832382 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
2022-11-30 21:15:33.835156 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.summary_preprocess.tab
2022-11-30 21:15:33.83764 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
[bam_translate] PG tag "A" on read "highqualAdapterContamIn3PrimeEnd:1:1:1:7#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInManyTxsOfMultiTxGene:1:1:1:16#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1MicrobialPE2MultimappingIntergenic:1:1:1:19#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1GeneFusionMidExonDiffChrPE2MultimappingIntergenic:1:1:1:25#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "T" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPE1UniqueUtrPE2MultimappingIntergenic:1:1:1:18#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
[bam_translate] PG tag "A" on read "highqualPEsInOneTxOfMultiTxGene:1:1:1:15#0" encountered with no corresponding entry in header, tag lost. Unknown tags are only reported once per input file for each tag ID.
2022-11-30 21:15:34.085552 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2022-11-30 21:15:34.093496 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.summary_alignment.tab
2022-11-30 21:15:34.101805 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.summary_analyzed_bamstats.tab
2022-11-30 21:15:34.104224 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2022-11-30 21:15:34.366959 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.summary_target_lengths.tab
2022-11-30 21:15:34.421895 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2022-11-30 21:15:34.471976 INFO::countGenomicFeatures.R/mergeCounts: starting...
2022-11-30 21:15:34.492895 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.counts_exon.tab
2022-11-30 21:15:34.506604 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.counts_exon_disjoint.tab
2022-11-30 21:15:34.515647 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.counts_gene.tab
2022-11-30 21:15:34.521743 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.counts_gene_coding.tab
2022-11-30 21:15:34.527606 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.counts_gene_exonic.tab
2022-11-30 21:15:34.533699 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.counts_intergenic.tab
2022-11-30 21:15:34.545722 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.counts_intron.tab
2022-11-30 21:15:34.549264 INFO::countGenomicFeatures.R/mergeCounts: done
2022-11-30 21:15:34.555912 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.summary_counts.tab
2022-11-30 21:15:34.557796 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2022-11-30 21:15:34.772165 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2022-11-30 21:15:36.925839 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.coverage.RData
2022-11-30 21:15:36.928943 INFO::coverage.R/saveCoverage: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.coverage.bw
2022-11-30 21:15:36.94098 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.summary_coverage.tab
2022-11-30 21:15:36.99338 INFO::analyzeVariants/analyzeVariants: starting ...
2022-11-30 21:15:37.060771 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:15:39.458116 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:15:39.522316 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:15:39.536556 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:15:39.537796 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.raw_variants.RData
2022-11-30 21:15:39.539253 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.filtered_variants.RData
2022-11-30 21:15:39.540322 INFO::analyzeVariants.R/wrap.callVariants: ...done
2022-11-30 21:15:39.541182 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2022-11-30 21:15:39.73053 INFO::analyzeVariants.R/writeVCF: ...done
2022-11-30 21:15:39.818089 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.mergeLanes.3b2ad7d0eb712/merged/results/merged.summary_variants.tab
2022-11-30 21:15:39.820161 INFO::analyzeVariants/analyzeVariants: done
2022-11-30 21:15:39.82385 INFO::mergeLanes.R/doMergeLanes: merge lanes successful.
 done successfully.



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



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



Executing test function test.preprocessReads  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:15:40.147473 INFO::preprocessReads.R/preprocessReads: starting...
2022-11-30 21:15:40.16958 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:15:40.185949 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2022-11-30 21:15:40.188663 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:15:43.072763 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:15:43.074315 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/chunks/chunk_000001/logs/progress.log
2022-11-30 21:15:45.828906 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.046 minutes
2022-11-30 21:15:45.877985 DEBUG::tools.R/processChunks: done
2022-11-30 21:15:45.880671 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:15:45.882454 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/results/test_pe.adapter_contaminated_1.RData
2022-11-30 21:15:45.884313 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2022-11-30 21:15:45.885841 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/results/test_pe.adapter_contaminated_2.RData
2022-11-30 21:15:45.893051 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
2022-11-30 21:15:45.89495 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/results/test_pe.summary_preprocess.tab
2022-11-30 21:15:45.897046 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/bams/processed.aligner_input_1.fastq ...
2022-11-30 21:15:45.900651 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/bams/processed.aligner_input_2.fastq ...
2022-11-30 21:15:45.90396 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/reports/shortReadReport_1 ...
2022-11-30 21:15:47.183795 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.preprocessReads.3b2ad74ade826d/reports/shortReadReport_2 ...
2022-11-30 21:15:48.527712 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads.minichunks  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:15:49.005743 INFO::preprocessReads.R/preprocessReads: starting...
2022-11-30 21:15:49.013884 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:15:49.018847 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_2.fastq
2022-11-30 21:15:49.022108 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:15:58.776919 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:15:58.80447 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/chunks/chunk_000001/logs/progress.log
2022-11-30 21:16:03.321204 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.075 minutes
2022-11-30 21:16:03.323863 DEBUG::tools.R/processChunks: starting chunkid= 2 ; see logfile= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/chunks/chunk_000002/logs/progress.log
2022-11-30 21:16:07.148389 DEBUG::tools.R/processChunks: done with chunkid= 2 ; elapsed.time= 0.064 minutes
2022-11-30 21:16:07.151715 DEBUG::tools.R/processChunks: starting chunkid= 3 ; see logfile= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/chunks/chunk_000003/logs/progress.log
2022-11-30 21:16:10.519775 DEBUG::tools.R/processChunks: done with chunkid= 3 ; elapsed.time= 0.056 minutes
2022-11-30 21:16:10.652185 DEBUG::tools.R/processChunks: done
2022-11-30 21:16:10.658689 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:16:10.662583 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/results/test_pe.adapter_contaminated_1.RData
2022-11-30 21:16:10.667664 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2022-11-30 21:16:10.671324 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/results/test_pe.adapter_contaminated_2.RData
2022-11-30 21:16:10.692021 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
2022-11-30 21:16:10.696599 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/results/test_pe.summary_preprocess.tab
2022-11-30 21:16:10.702297 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/bams/processed.aligner_input_1.fastq ...
2022-11-30 21:16:10.710539 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/bams/processed.aligner_input_2.fastq ...
2022-11-30 21:16:10.717118 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/reports/shortReadReport_1 ...
2022-11-30 21:16:12.537135 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.preprocessReads.minichunks.3b2ad75393a7b7/reports/shortReadReport_2 ...
2022-11-30 21:16:13.663139 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



Executing test function test.preprocessReads_single_end  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:16:13.980371 INFO::preprocessReads.R/preprocessReads: starting...
2022-11-30 21:16:14.001707 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/test-data/unit_tests_1.fastq
2022-11-30 21:16:14.004526 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:16:18.376175 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:16:18.379664 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= /tmp/Rtmpl0lppe/test.preprocessReads_single_end.3b2ad75b695572/chunks/chunk_000001/logs/progress.log
2022-11-30 21:16:21.242005 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.048 minutes
2022-11-30 21:16:21.26401 DEBUG::tools.R/processChunks: done
2022-11-30 21:16:21.268919 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:16:21.272171 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads_single_end.3b2ad75b695572/results/test_se.adapter_contaminated_1.RData
2022-11-30 21:16:21.285983 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
2022-11-30 21:16:21.289823 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.preprocessReads_single_end.3b2ad75b695572/results/test_se.summary_preprocess.tab
2022-11-30 21:16:21.293941 INFO::preprocessReads.R/mergePreprocessedReads: merging file= /tmp/Rtmpl0lppe/test.preprocessReads_single_end.3b2ad75b695572/bams/processed.aligner_input_1.fastq ...
2022-11-30 21:16:21.302236 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= /tmp/Rtmpl0lppe/test.preprocessReads_single_end.3b2ad75b695572/reports/shortReadReport_1 ...
2022-11-30 21:16:23.83497 INFO::preprocessReads.R/preprocessReads: done
 done successfully.



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



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



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



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



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



Executing test function test.runPipeline  ... checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:16:25.506935 INFO::preprocessReads.R/preprocessReads: starting...
2022-11-30 21:16:25.552387 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/extdata/H1993_TP53_subset2500_1.fastq.gz
2022-11-30 21:16:25.600643 INFO::io.R/FastQStreamer.init: initialised FastQ streamer for filename= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/extdata/H1993_TP53_subset2500_2.fastq.gz
2022-11-30 21:16:25.608552 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:16:35.069169 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:16:35.074378 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2022-11-30 21:16:38.327262 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.054 minutes
2022-11-30 21:16:38.499593 DEBUG::tools.R/processChunks: done
2022-11-30 21:16:38.505827 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_1 ...
2022-11-30 21:16:38.510024 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_1.RData
2022-11-30 21:16:38.514767 INFO::detectAdapterContam.R/mergeDetectAdapterContam: merging file= adapter_contaminated_2 ...
2022-11-30 21:16:38.518759 INFO::io.R/saveWithID: saving file= test/results/test.adapter_contaminated_2.RData
2022-11-30 21:16:38.539159 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
2022-11-30 21:16:38.544097 INFO::io.R/saveWithID: saving file= test/results/test.summary_preprocess.tab
2022-11-30 21:16:38.549489 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_1.fastq ...
2022-11-30 21:16:38.559593 INFO::preprocessReads.R/mergePreprocessedReads: merging file= test/bams/processed.aligner_input_2.fastq ...
2022-11-30 21:16:38.569256 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_1 ...
2022-11-30 21:16:41.568722 INFO::preprocessReads.R/buildShortReadReports: generating report_dir= test/reports/shortReadReport_2 ...
2022-11-30 21:16:43.457184 INFO::preprocessReads.R/preprocessReads: done
2022-11-30 21:16:43.664097 INFO::alignReads.R/alignReads: starting alignment...
2022-11-30 21:16:43.671412 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:16:51.030486 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:16:51.033174 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.
2022-11-30 21:16:55.647068 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.077 minutes
2022-11-30 21:16:55.649778 DEBUG::tools.R/processChunks: done
2022-11-30 21:16:55.651399 INFO::alignReads.R/mergeBAMsAcrossDirs: starting...
2022-11-30 21:16:55.686511 INFO::alignReads.R/mergeBAMsAcrossDirs: done
2022-11-30 21:16:55.692875 INFO::io.R/saveWithID: saving file= test/results/test.summary_alignment.tab
2022-11-30 21:16:55.698013 INFO::io.R/saveWithID: saving file= test/results/test.summary_analyzed_bamstats.tab
2022-11-30 21:16:55.700078 INFO::reportPipelineQA.R/writePreprocessAlignReport: creating joint preprocess-alignment report...
2022-11-30 21:16:55.856537 INFO::io.R/saveWithID: saving file= test/results/test.summary_target_lengths.tab
2022-11-30 21:16:55.905152 INFO::reportPipelineQA.R/writePreprocessAlignReport: done
2022-11-30 21:16:55.906363 INFO::alignReads.R/alignReads: done
2022-11-30 21:16:56.039899 INFO::countGenomicFeatures.R/countGenomicFeatures: starting...
2022-11-30 21:16:56.060985 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:16:59.568093 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:16:59.570208 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2022-11-30 21:17:02.14341 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.043 minutes
2022-11-30 21:17:02.146062 DEBUG::tools.R/processChunks: done
2022-11-30 21:17:02.147949 INFO::countGenomicFeatures.R/mergeCounts: starting...
2022-11-30 21:17:02.159391 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon.tab
2022-11-30 21:17:02.170051 INFO::io.R/saveWithID: saving file= test/results/test.counts_exon_disjoint.tab
2022-11-30 21:17:02.178108 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene.tab
2022-11-30 21:17:02.183183 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_coding.tab
2022-11-30 21:17:02.188141 INFO::io.R/saveWithID: saving file= test/results/test.counts_gene_exonic.tab
2022-11-30 21:17:02.192887 INFO::io.R/saveWithID: saving file= test/results/test.counts_intergenic.tab
2022-11-30 21:17:02.200238 INFO::io.R/saveWithID: saving file= test/results/test.counts_intron.tab
2022-11-30 21:17:02.204448 INFO::countGenomicFeatures.R/mergeCounts: done
2022-11-30 21:17:02.208904 INFO::io.R/saveWithID: saving file= test/results/test.summary_counts.tab
2022-11-30 21:17:02.211163 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: creating report of genomic features counts...
2022-11-30 21:17:02.438913 INFO::reportPipelineQA.R/writeGenomicFeaturesReport: done
2022-11-30 21:17:02.440079 INFO::countGenomicFeatures.R/countGenomicFeatures: done...
2022-11-30 21:17:02.541525 INFO::coverage.R/calculateCoverage: starting...
2022-11-30 21:17:02.546103 DEBUG::tools.R/processChunks: starting...
2022-11-30 21:17:07.097129 DEBUG::tools.R/processChunks: waiting for chunkid=[  ] ...
2022-11-30 21:17:07.09926 DEBUG::tools.R/processChunks: starting chunkid= 1 ; see logfile= test/chunks/chunk_000001/logs/progress.log
2022-11-30 21:17:09.438547 DEBUG::tools.R/processChunks: done with chunkid= 1 ; elapsed.time= 0.039 minutes
2022-11-30 21:17:09.441171 DEBUG::tools.R/processChunks: done
2022-11-30 21:17:10.947699 INFO::io.R/saveWithID: saving file= test/results/test.coverage.RData
2022-11-30 21:17:10.949492 INFO::coverage.R/saveCoverage: saving file= test/results/test.coverage.bw
2022-11-30 21:17:11.023698 INFO::io.R/saveWithID: saving file= test/results/test.summary_coverage.tab
2022-11-30 21:17:11.02528 INFO::coverage.R/calculateCoverage: done
2022-11-30 21:17:11.027239 INFO::analyzeVariants/analyzeVariants: starting ...
2022-11-30 21:17:11.119954 INFO::analyzeVariants.R/wrap.callVariants: Tallying variants...
2022-11-30 21:17:21.755919 INFO::analyzeVariants.R/wrap.callVariants: calling variants...
2022-11-30 21:17:21.822944 INFO::analyzeVariants.R/wrap.postFilerVariants: post filtering variants...
2022-11-30 21:17:21.837427 INFO::analyzeVariants.R/wrap.callVariants: Saving GRanges of raw and filtered variants...
2022-11-30 21:17:21.838652 INFO::io.R/saveWithID: saving file= test/results/test.raw_variants.RData
2022-11-30 21:17:21.841301 INFO::io.R/saveWithID: saving file= test/results/test.filtered_variants.RData
2022-11-30 21:17:21.842558 INFO::analyzeVariants.R/wrap.callVariants: ...done
2022-11-30 21:17:21.84343 INFO::analyzeVariants.R/writeVCF: writing vcf file...
2022-11-30 21:17:22.037549 INFO::analyzeVariants.R/writeVCF: ...done
2022-11-30 21:17:22.132907 INFO::io.R/saveWithID: saving file= test/results/test.summary_variants.tab
2022-11-30 21:17:22.134993 INFO::analyzeVariants/analyzeVariants: done
2022-11-30 21:17:22.142001 INFO::Pipeline run successful.
 done successfully.



Executing test function test.calculateTargetLength  ... checkConfig.R/checkConfig.template: loading template config= //tmp/Rtmpl0lppe/tp53-config.txt 
checkConfig.R/checkConfig.template: loading template config= /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/config/default-config.txt 
2022-11-30 21:17:22.436625 INFO::io.R/saveWithID: saving file= /tmp/Rtmpl0lppe/test.calcTargetLengths.3b2ad7754b5115/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 -- Wed Nov 30 21:17:38 2022 
*********************************************** 
Number of test functions: 62 
Number of deactivated test functions: 10 
Number of errors: 1 
Number of failures: 0 

 
1 Test Suite : 
HTSeqGenie unit testing - 62 test functions, 1 error, 0 failures
DEACTIVATED test.annotateVariants: Skipped annotateVariants() test
ERROR in test.wrap.callVariants.parallel: Error in manager$availability[[as.character(result$node)]] <- TRUE : 
  wrong args for environment subassignment
DEACTIVATED test.callVariantsGATK: callVariantsGATK() tests need gatk.path option set
DEACTIVATED test.callVariantsGATK.withFiltering: callVariantsGATK() tests need gatk.path option set
DEACTIVATED test.checkGATKJar: checkGATKJar() test needs gatk.path option set
DEACTIVATED test.gatk: gatk() tests need gatk.path option set
DEACTIVATED test.realignIndels: test.realignIndels() tests need gatk.path option set
DEACTIVATED test.realignIndelsGATK: realignIndelsGATK() tests need gatk.path option set
DEACTIVATED test.realignIndelsGATK.parallel: realignIndelsGATK() tests need gatk.path option set
DEACTIVATED test.markDuplicates: Skipped markDuplicates() test
DEACTIVATED test.markDuplicates_w_outfile: Skipped markDuplicates() test



Details 
*************************** 
Test Suite: HTSeqGenie unit testing 
Test function regexp: ^test.+ 
Test file regexp: ^runit.+\.[rR]$ 
Involved directory: 
/home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests 
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.alignReads.R 
test.alignReads: (2 checks) ... OK (26.49 seconds)
test.alignReads.sparsechunks: (2 checks) ... OK (17.34 seconds)
test.alignReadsOneSingleEnd: (2 checks) ... OK (0.59 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.analyzeVariants.R 
test.annotateVariants : DEACTIVATED, Skipped annotateVariants() test
test.callVariantsVariantTools.genotype: (2 checks) ... OK (58.71 seconds)
test.wrap.callVariants: (4 checks) ... OK (9.8 seconds)
test.wrap.callVariants.filters: (2 checks) ... OK (18.93 seconds)
test.wrap.callVariants.parallel: ERROR !! 
Error in manager$availability[[as.character(result$node)]] <- TRUE : 
  wrong args for environment subassignment
test.wrap.callVariants.which: (1 checks) ... OK (3.08 seconds)
test.writeVCF.NULL: (1 checks) ... OK (0.15 seconds)
test.writeVCF.vcfStat: (4 checks) ... OK (0.49 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.bamUtils.R 
test.isFirstFragment: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.buildGenomicFeatures.R 
test.buildCountsGRangesList: (3 checks) ... OK (28 seconds)
test.generateSingleGeneDERs: (4 checks) ... OK (23.57 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.calculateCoverage.R 
test.computeCoverage: (9 checks) ... OK (0.67 seconds)
test.isSparse: (5 checks) ... OK (0.09 seconds)
test.mergeCoverage: (1 checks) ... OK (1.3 seconds)
test.mergeCoverage.sparse: (2 checks) ... OK (1.22 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.checkConfig.R 
test.checkConfig.analyzeVariants: (5 checks) ... OK (0.17 seconds)
test.findTemplate: (5 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.config.R 
test.checkConfig: (5 checks) ... OK (0.37 seconds)
test.checkConfig.alignReads: (5 checks) ... OK (0.41 seconds)
test.getConfig: (14 checks) ... OK (0 seconds)
test.loadConfig: (2 checks) ... OK (0 seconds)
test.parseDCF: (7 checks) ... OK (0 seconds)
test.updateConfig: (1 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.detectAdapterContam.R 
test.getAdapterSeqs: (5 checks) ... OK (0.05 seconds)
test.isAdapter: (5 checks) ... OK (0.12 seconds)
test.isAdapter3.primeEnd: (1 checks) ... OK (0.08 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.detectRRNA.R 
test.detectRRNA: (1 checks) ... OK (0.39 seconds)
test.detectRRNA.paired_end: (1 checks) ... OK (0.47 seconds)
test.getRRNAIds: (1 checks) ... OK (0.3 seconds)
test.getRRNAIds_random: (1 checks) ... OK (0.25 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.filterQuality.R 
test.filterByLength: (2 checks) ... OK (0.06 seconds)
test.isAboveQualityThresh: (3 checks) ... OK (0.04 seconds)
test.trimTailsByQuality: (4 checks) ... OK (0.03 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/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.15 seconds)
test.gatk : DEACTIVATED, gatk() tests need gatk.path option set
test.realignIndels : DEACTIVATED, test.realignIndels() tests need gatk.path option set
test.realignIndelsGATK : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test.realignIndelsGATK.parallel : DEACTIVATED, realignIndelsGATK() tests need gatk.path option set
test_zipUp: (3 checks) ... OK (0 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.io.R 
test.FastQStreamer.getReads.pefq: (1 checks) ... OK (0.21 seconds)
test.FastQStreamer.getReads.pefq.subsample: (1 checks) ... OK (0.38 seconds)
test.FastQStreamer.getReads.segz: (1 checks) ... OK (0.19 seconds)
test.FastQStreamer.getReads.truncated: (1 checks) ... OK (0.24 seconds)
test.FastQStreamer.subsampler.isdeterministic: (3 checks) ... OK (0.64 seconds)
test.createTmpDir: (4 checks) ... OK (0 seconds)
test.detectQualityInFASTQFile: (3 checks) ... OK (0.15 seconds)
test.getObjectFilename: (4 checks) ... OK (0 seconds)
test.safeUnlink: (2 checks) ... OK (0 seconds)
test.writeAudit: (0 checks) ... OK (0.22 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.mergeLanes.R 
test.mergeLanes: (6 checks) ... OK (57.99 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.picard.R 
test.markDuplicates : DEACTIVATED, Skipped markDuplicates() test
test.markDuplicates_w_outfile : DEACTIVATED, Skipped markDuplicates() test
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.preprocessReads.R 
test.preprocessReads: (5 checks) ... OK (8.66 seconds)
test.preprocessReads.minichunks: (5 checks) ... OK (25.13 seconds)
test.preprocessReads_single_end: (5 checks) ... OK (10.17 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.readRNASeqEnds.R 
test.readRNASeqEnds: (6 checks) ... OK (0.24 seconds)
test.readRNASeqEnds.dupmark: (2 checks) ... OK (0.28 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.reportPipelineQA.R 
test.how_many: (3 checks) ... OK (0.01 seconds)
test.plotDF: (3 checks) ... OK (0.23 seconds)
test.relativeBarPlot: (2 checks) ... OK (0.1 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.runPipeline.R 
test.runPipeline: (1 checks) ... OK (57.43 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.targetLengths.R 
test.calculateTargetLength: (4 checks) ... OK (0.3 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.tools.R 
test.sclapply: (10 checks) ... OK (15.8 seconds)
test.tryKeepTraceback: (3 checks) ... OK (0.01 seconds)
--------------------------- 
Test file: /home/biocbuild/bbs-3.17-bioc/R/library/HTSeqGenie/unitTests/runit.trimReads.R 
test.truncateReads: (7 checks) ... OK (0.06 seconds)
test.truncateReads.trim5: (15 checks) ... OK (0.15 seconds) 

Error in eval(ei, envir) : 
  runTests.R: failed to run unit tests, see /home/biocbuild/bbs-3.17-bioc/meat/HTSeqGenie.Rcheck/tests/HTSeqGenie-runit.txt for details
Calls: source -> withVisible -> eval -> eval
In addition: There were 50 or more warnings (use warnings() to see the first 50)
Execution halted

Example timings

HTSeqGenie.Rcheck/HTSeqGenie-Ex.timings

nameusersystemelapsed
HTSeqGenie0.0010.0000.001
buildGenomicFeaturesFromTxDb000
runPipeline0.0010.0000.000