Random errors, again

[lgatto]

Some errors have now popped up on Bioc server (https://www.bioconductor.org/checkResults/3.5/bioc-LATEST/MSnbase/veracruz2-checksrc.html) that don't seem related to any changes I have done. Locally, I can't reproduce, although in a test yesterday, I had a different error. Last local check worked.

* checking examples ... OK
* checking for unstated dependencies in ‘tests’ ... OK
* checking tests ...
  Running ‘testthat.R’
 OK
* checking for unstated dependencies in vignettes ... OK

@jotsetung - have you observed anything suspicious?

[jorainer]

hm, I guess the errors did already disappear. So far I didn't see any problems anymore with random errors - and I'm reading lots of files in and use spectrapply and spectra on OnDiskMSnExp a lot. In any rate, I'm running now the torture test again - just to be sure.

[lgatto]

Disappear? I still see them on the Bioc server. Note that I see 2 different errors on the 2 failing platforms. I just checked the package locally again and I get a different error

* checking tests ...
  Running ‘testthat.R’
 ERROR
Running the tests in ‘tests/testthat.R’ failed.
Last 13 lines of output:
   Description:
    my description
   10 features of interest:
     P20353, P53501  ...  Q9VCK0, Q9VIU7
  A collection of 1 features of interest.
  A collection of 10 features of interest.
  Iterations of EM: 
  1...2...3...4...5...6...7...8...9...10...11...
  [1] 0.07947339
  testthat results ================================================================
  OK: 1320 SKIPPED: 0 FAILED: 1
  1. Error: Coercion to MSnExp (@test_OnDiskMSnExp.R#50) 
  
  Error: testthat unit tests failed
  Execution halted
* checking for unstated dependencies in vignettes ... OK

and a clean test

* checking tests ...
  Running ‘testthat.R’
 OK
* checking for unstated dependencies in vignettes ... OK

It's not a good time for that nonsense! :-/

[jorainer]

a sorry, the link was to the build report on veracruz2, didn't realize the others have errors. Will also check.

[jorainer]

Very bad timing indeed. So far I can not reproduce any of the errors.

The one on toluca2 looks pretty familiar (this mysterious bugger that we thought to be solved). One very wild guess is that the parallel processing on OS X might be involved in that problem. I experienced problems (delays and sometimes failure of the master task to talk to the forked processes) on macOS with the multicore package, i.e. when MulticoreParam is used (the default for Linux and Mac OS).
We could add a register(SerialParam()) to testthat.R - just to be avoid any such problems.

I'll keep on testing and will test also on linux.

[lgatto]

I just ran two successful checks on linux...

[jorainer]

Did 9 successful tests now on macOS. Did you have the failing test(s) with the released R? I ran all my tests on a fresh install from today.

my session info:

> sessionInfo()
R version 3.4.0 (2017-04-21)
Platform: x86_64-apple-darwin16.6.0/x86_64 (64-bit)
Running under: macOS Sierra 10.12.5

Matrix products: default
BLAS: /System/Library/Frameworks/Accelerate.framework/Versions/A/Frameworks/vecLib.framework/Versions/A/libBLAS.dylib
LAPACK: /System/Library/Frameworks/Accelerate.framework/Versions/A/Frameworks/vecLib.framework/Versions/A/libLAPACK.dylib

locale:
[1] en_US.UTF-8/en_US.UTF-8/en_US.UTF-8/C/en_US.UTF-8/en_US.UTF-8

attached base packages:
[1] parallel  stats     graphics  grDevices utils     datasets  methods  
[8] base     

other attached packages:
[1] MSnbase_2.1.18      ProtGenerics_1.7.0  BiocParallel_1.9.6 
[4] mzR_2.9.10          Rcpp_0.12.10        Biobase_2.35.1     
[7] BiocGenerics_0.21.3

loaded via a namespace (and not attached):
 [1] IRanges_2.9.19        zlibbioc_1.21.0       doParallel_1.0.10    
 [4] munsell_0.4.3         colorspace_1.3-2      impute_1.49.0        
 [7] lattice_0.20-35       foreach_1.4.3         plyr_1.8.4           
[10] mzID_1.13.0           grid_3.4.0            gtable_0.2.0         
[13] affy_1.53.0           iterators_1.0.8       digest_0.6.12        
[16] lazyeval_0.2.0        tibble_1.3.0          preprocessCore_1.37.0
[19] affyio_1.45.0         ggplot2_2.2.1         S4Vectors_0.13.16    
[22] codetools_0.2-15      MALDIquant_1.16.2     limma_3.31.21        
[25] BiocInstaller_1.25.3  compiler_3.4.0        pcaMethods_1.67.0    
[28] scales_0.4.1          stats4_3.4.0          XML_3.98-1.6         
[31] vsn_3.43.10          
> 

[jorainer]

strange, today toluca2 is OK, but veracruz has the same error tokay2 had before:

* checking tests ...
  Running ‘testthat.R’
 ERROR
Running the tests in ‘tests/testthat.R’ failed.
Last 13 lines of output:
   Description:
    my description
   10 features of interest:
     P20353, P53501  ...  Q9VCK0, Q9VIU7
  A collection of 1 features of interest.
  A collection of 10 features of interest.
  Iterations of EM: 
  1...2...3...4...5...6...7...8...9...10...11...
  [1] 0.07947339
  testthat results ================================================================
  OK: 1321 SKIPPED: 0 FAILED: 1
  1. Failure: Compare OnDiskMSnExp and MSnExp extractPrecSpectra (@test_OnDiskMSnExp_other_methods.R#120) 
  
  Error: testthat unit tests failed
  Execution halted

I'm running now the torture tests since I cannot reproduce this error. To me it seems that tests on tokay2 are not stable, for ensembldb I get from time to time TIMEOUT errors building the vignette - although there is nothing in it that might delay execution.

[lgatto]

I have

> sessionInfo()
R Under development (unstable) (2017-02-25 r72256)
Platform: x86_64-pc-linux-gnu (64-bit)
Running under: Ubuntu 14.04.5 LTS

Matrix products: default
BLAS: /usr/lib/atlas-base/libf77blas.so.3.0
LAPACK: /usr/lib/lapack/liblapack.so.3.0

locale:
 [1] LC_CTYPE=en_GB.UTF-8       LC_NUMERIC=C              
 [3] LC_TIME=en_GB.UTF-8        LC_COLLATE=en_GB.UTF-8    
 [5] LC_MONETARY=en_GB.UTF-8    LC_MESSAGES=en_GB.UTF-8   
 [7] LC_PAPER=en_GB.UTF-8       LC_NAME=C                 
 [9] LC_ADDRESS=C               LC_TELEPHONE=C            
[11] LC_MEASUREMENT=en_GB.UTF-8 LC_IDENTIFICATION=C       

attached base packages:
[1] parallel  stats     graphics  grDevices utils     datasets  methods  
[8] base     

other attached packages:
[1] MSnbase_2.1.18      ProtGenerics_1.7.0  BiocParallel_1.9.6 
[4] mzR_2.9.10          Rcpp_0.12.10        Biobase_2.35.1     
[7] BiocGenerics_0.21.3

loaded via a namespace (and not attached):
 [1] IRanges_2.9.19        zlibbioc_1.21.0       doParallel_1.0.10    
 [4] munsell_0.4.3         colorspace_1.3-2      impute_1.49.0        
 [7] lattice_0.20-35       foreach_1.4.3         msdata_0.15.1        
[10] plyr_1.8.4            mzID_1.13.0           grid_3.4.0           
[13] gtable_0.2.0          affy_1.53.0           iterators_1.0.8      
[16] digest_0.6.12         lazyeval_0.2.0        tibble_1.3.0         
[19] preprocessCore_1.37.0 affyio_1.45.0         ggplot2_2.2.1        
[22] S4Vectors_0.13.15     codetools_0.2-15      MALDIquant_1.16.2    
[25] limma_3.31.21         BiocInstaller_1.25.3  compiler_3.4.0       
[28] pcaMethods_1.67.0     scales_0.4.1          stats4_3.4.0         
[31] XML_3.98-1.6          vsn_3.43.10          

As toluca2 has fixed itself, I don't think we should do anything. I will get back in touch with the Bioc core member to explain the situation.

[jorainer]

I am running today repeatedly tests - no error so far. The torture tests did also not report anything yet - am in iterations 6000 for readMSData and readMSData2 as well as extracting spectra from OnDiskMSnExp.

In the long run it might be helpful to add the register(SerialParam()) to the testthat.R also because not the complete error stack is returned/shown if functions run in parallel mode.

[lgatto]

Ok, good idea to use register(SerialParam()). And thanks for the tests.

[jorainer]

15000 times reading data with readMSData2 and accessing either a single spectrum (with [[) or all spectra (with spectra) and not a single error/problem.

[lgatto]

Now, the errors on the mac platforms have disappeared, but checks on Windows and Linux fail: http://master.bioconductor.org/checkResults/3.5/bioc-LATEST/MSnbase/. Oh dear!?!

[jorainer]

I don't understand that. The torture test running 10000 times readMSData did pass too without problems! It's hard to fix if I cannot reproduce the error.

[lgatto]

Yes, I agree. We have done everything we could at this stage. Thank you for your help.

[lgatto]

FYI

commit 720eda7cc6ffb898f2d67f65bc72f0e4c907e8ea
Author: Laurent <lg390@cam.ac.uk>
Date:   Mon Apr 24 06:13:14 2017 +0100

    use serial params

[jorainer]

I was thinking over the error on malbec2:

1. Error: isolation window (@test_MSnExp.R#332) --------------------------------
attempt to apply non-function
1: isolationWindow(readMSData(f), unique = FALSE) at testthat/test_MSnExp.R:332
2: readMSData(f)
3: new("Spectrum2", msLevel = as.integer(hd$msLevel), merged = as.numeric(hd$mergedScan), 
       precScanNum = as.integer(scanNums[i]), precursorMz = hd$precursorMZ, precursorIntensity = hd$precursorIntensity, 
       precursorCharge = as.integer(hd$precursorCharge), collisionEnergy = hd$collisionEnergy, 
       rt = hd$retentionTime, acquisitionNum = as.integer(hd$acquisitionNum), scanIndex = as.integer(hd$seqNum), 
       tic = hd$totIonCurrent, mz = .p[, 1], intensity = .p[, 2], fromFile = as.integer(filen), 
       centroided = as.logical(centroided.), smoothed = as.logical(smoothed.), polarity = as.integer(hd$polarity))
4: initialize(value, ...)
5: initialize(value, ...)
6: callNextMethod(.Object, ...)
7: eval(call, callEnv)
8: eval(call, callEnv)
9: .nextMethod(.Object, ...)
10: .local(.Object, ...)
11: callNextMethod(.Object, ..., mz = mz[o], intensity = intensity[o], peaksCount = length(mz))
12: addNextMethod(method, f, envir = methodEnv)
13: addNextMethod(method, f, envir = methodEnv)
14: .findNextFromTable(method, f, optional, envir)
15: .findInheritedMethods(defined, fdef, mtable = NULL, table = allTable, excluded = excluded)
16: (function (x) 
   x$.self$finalize())(<environment>)

This could be related to the attempt to apply non-function that occurred randomly (issue #151). Based on http://r.789695.n4.nabble.com/Reference-class-finalize-fails-with-attempt-to-apply-non-function-td4174697.html it could be that this elusive bug might be related to, or even be triggered by, the gc() that we introduced to fix issue #151.

I'm now evaluating whether we still need the gc() calls after reading data from mzML files. For performance reasons it would also be nice to get rid of them.

[stanstrup]

This is related?

raw <- factors %>%
             pull(filepath) %>%
             readMSData(pdata = new("NAnnotatedDataFrame", factors), mode = "inMemory", msLevel. = 1)

Error in x$.self$finalize() : attempt to apply non-function

I didn't see that before. But I just changed to inMemory.

[jorainer]

It is strange that you see that for inMemory. I do see it occasionally for onDisk. I have absolutely no clue how we could avoid this (or even what it is causing or if this has any consequences). I was even once suspecting Rcpp (RcppCore/Rcpp#547).

Well, looks like I'll have to spend some time again trying to hunt that down :(