05 Simulation Experiments

Eliot J. B. McIntire

November 27 2019

Source: vignettes/v-experiments.Rmd

Running a groups of simulations: the experiment function

Once a simulation is properly initialized and runs correctly with the spades function, it is likely time to do things like run replicates. There are two functions, experiment and experiment2 to do this. These both give opportunities to create simulation experiments, such as through varying parameters and modules. experiment is for simpler “fully factorial” cases, and experiment2 can take any simList class objects for the simulation experiment. With experiment, for example, you can pass alternative values to parameters in modules and the experiment will build a fully factorial experiment, with replication and run them. This function (as with POM and splitRaster) is parallel-aware and can either proceed with a cluster object (cl argument) or a cluster running in the background using the raster::beginCluster.

library(SpaDES.experiment)
## Loading required package: reproducible
## Loading required package: SpaDES.core
## Loading required package: quickPlot
## 
## Attaching package: 'SpaDES.core'
## The following objects are masked from 'package:stats':
## 
##     end, start
## The following object is masked from 'package:utils':
## 
##     citation
## 
## Attaching package: 'SpaDES.experiment'
## The following objects are masked from 'package:SpaDES.core':
## 
##     experiment, experiment2, POM, simInitAndExperiment
tmpdir <- file.path(tempdir(), "experiment")

# Copy Example 5 here:
mySim <- simInit(
  times = list(start = 0.0, end = 2.0, timeunit = "year"),
  params = list(.globals = list(stackName = "landscape", burnStats = "nPixelsBurned")),
  modules = list("randomLandscapes", "fireSpread", "caribouMovement"),
  paths = list(modulePath = system.file("sampleModules", package = "SpaDES.core"),
               outputPath = tmpdir),
  # Save final state of landscape and caribou
  outputs = data.frame(objectName = c("landscape", "caribou"), stringsAsFactors = FALSE)
)
## Setting:
##   options(
##     spades.outputPath = 'C:/Users/emcintir/AppData/Local/Temp/Rtmpc7R4oH/experiment'
##     spades.modulePath = 'C:/Eliot/R/win-library/4.0/SpaDES.core/sampleModules'
##   )
## Paths set to:
##   options(
##     rasterTmpDir = 'C:/Users/emcintir/AppData/Local/Temp/Rtmpc7R4oH/raster'
##     reproducible.cachePath = 'C:/Users/emcintir/AppData/Local/Temp/Rtmpc7R4oH/reproducible/cache'
##     spades.inputPath = 'C:/Users/emcintir/AppData/Local/Temp/RtmpiQEaVL/SpaDES/inputs'
##     spades.outputPath = 'C:/Users/emcintir/AppData/Local/Temp/Rtmpc7R4oH/experiment'
##     spades.modulePath = 'C:/Eliot/R/win-library/4.0/SpaDES.core/sampleModules'
##   )
## Loading required package: raster
## Loading required package: sp
## Loading required package: RColorBrewer
## Loading required package: SpaDES.tools
## Registered S3 methods overwritten by 'ffbase':
##   method   from
##   [.ff     ff  
##   [.ffdf   ff  
##   [<-.ff   ff  
##   [<-.ffdf ff
## Loading required package: grid
## 
## Attaching package: 'grid'
## The following object is masked from 'package:quickPlot':
## 
##     gpar
## defineParameter: '.useCache' is not of specified type 'logical'.
## randomLandscapes: inputObjects: stackName is used from sim inside doEvent.randomLandscapes, but is not declared in metadata inputObjects
## fireSpread: module code: landscape, nPixelsBurned are declared in metadata inputObjects, but no default(s) are provided in .inputObjects
## fireSpread: inputObjects: stackName, DEM, Fires are used from sim inside doEvent.fireSpread, but are not declared in metadata inputObjects
## caribouMovement: module code: landscape is declared in metadata inputObjects, but no default(s) is provided in .inputObjects
## caribouMovement: inputObjects: habitatQuality is used from sim inside Move, but is not declared in metadata inputObjects
sims <- experiment(mySim, replicates = 2, .plotInitialTime = NA) # no plotting
## [1] "2019-11-27 09:15:32 | total elpsd: 0 secs | 0 checkpoint init 0"
## [1] "2019-11-27 09:15:32 | total elpsd: 0 secs | 0 save init 0"
## [1] "2019-11-27 09:15:32 | total elpsd: 0 secs | 0 progress init 0"
## [1] "2019-11-27 09:15:32 | total elpsd: 0 secs | 0 load init 0"
## [1] "2019-11-27 09:15:32 | total elpsd: 0 secs | 0 randomLandscapes init 1"
## Loading required namespace: RandomFields
## [1] "2019-11-27 09:15:33 | total elpsd: 1.1 secs | 0 fireSpread init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$startTime, "fireSpread", 
##     "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.1 secs | 0 caribouMovement init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$moveInitialTime, "caribouMovement", 
##     "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.2 secs | 1 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$returnInterval, 
##     "fireSpread", "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.2 secs | 1 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.3 secs | 1 fireSpread stats 5"
## [1] "2019-11-27 09:15:33 | total elpsd: 1.3 secs | 1.08333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.3 secs | 1.16666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.3 secs | 1.25 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.3 secs | 1.33333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:33 | total elpsd: 1.3 secs | 1.41666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.3 secs | 1.5 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.3 secs | 1.58333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.3 secs | 1.66666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.3 secs | 1.75 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.3 secs | 1.83333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.3 secs | 1.91666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.3 secs | 2 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.4 secs | 2 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 1.4 secs | 2 fireSpread stats 5"
## [1] "2019-11-27 09:15:34 | total elpsd: 1.4 secs | 2 save spades 10"
## simList saved in
##  SpaDES.core:::.pkgEnv$.sim 
## It will be deleted at next spades() call.
## [1] "2019-11-27 09:15:34 | total elpsd: 0 secs | 0 checkpoint init 0"
## [1] "2019-11-27 09:15:34 | total elpsd: 0 secs | 0 save init 0"
## [1] "2019-11-27 09:15:34 | total elpsd: 0 secs | 0 progress init 0"
## [1] "2019-11-27 09:15:34 | total elpsd: 0 secs | 0 load init 0"
## [1] "2019-11-27 09:15:34 | total elpsd: 0 secs | 0 randomLandscapes init 1"
## [1] "2019-11-27 09:15:34 | total elpsd: 0.78 secs | 0 fireSpread init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$startTime, "fireSpread", 
##     "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 0.8 secs | 0 caribouMovement init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$moveInitialTime, "caribouMovement", 
##     "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 0.81 secs | 1 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$returnInterval, 
##     "fireSpread", "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 0.81 secs | 1 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:34 | total elpsd: 0.83 secs | 1 fireSpread stats 5"
## [1] "2019-11-27 09:15:34 | total elpsd: 0.83 secs | 1.08333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.84 secs | 1.16666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.84 secs | 1.25 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.86 secs | 1.33333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.86 secs | 1.41666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.88 secs | 1.5 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.89 secs | 1.58333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.89 secs | 1.66666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.91 secs | 1.75 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.91 secs | 1.83333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.91 secs | 1.91666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.92 secs | 2 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.94 secs | 2 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:35 | total elpsd: 0.94 secs | 2 fireSpread stats 5"
## [1] "2019-11-27 09:15:35 | total elpsd: 0.95 secs | 2 save spades 10"
## simList saved in
##  SpaDES.core:::.pkgEnv$.sim 
## It will be deleted at next spades() call.
## shutting down parallel nodes
attr(sims, "experiment")$expDesign # shows 2 replicates of same experiment
##   modules expLevel replicate
## 1       1        1         1
## 2       1        1         2

Caching at the experiment level

As with spades, an experiment can be cached.

At the experiment level

This functionality can be achieved within an experiment call. This can be done 2 ways, either: “internally” through the cache argument, which will cache each spades call; or, “externally” which will cache the entire experiment. If there are lots of spades calls, then the former will be slow as the simList will be digested once per spades call.

Using cache argument

system.time({
  sims1 <- experiment(mySim, replicates = 2, cache = TRUE, .plotInitialTime = NA)
})
## [1] "2019-11-27 09:15:35 | total elpsd: 0 secs | 0 checkpoint init 0"
## [1] "2019-11-27 09:15:35 | total elpsd: 0 secs | 0 save init 0"
## [1] "2019-11-27 09:15:35 | total elpsd: 0.016 secs | 0 progress init 0"
## [1] "2019-11-27 09:15:35 | total elpsd: 0.016 secs | 0 load init 0"
## [1] "2019-11-27 09:15:35 | total elpsd: 0.016 secs | 0 randomLandscapes init 1"
## [1] "2019-11-27 09:15:36 | total elpsd: 0.73 secs | 0 fireSpread init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$startTime, "fireSpread", 
##     "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.75 secs | 0 caribouMovement init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$moveInitialTime, "caribouMovement", 
##     "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.75 secs | 1 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$returnInterval, 
##     "fireSpread", "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.77 secs | 1 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.8 secs | 1 fireSpread stats 5"
## [1] "2019-11-27 09:15:36 | total elpsd: 0.8 secs | 1.08333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.8 secs | 1.16666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.82 secs | 1.25 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.82 secs | 1.33333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.84 secs | 1.41666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.84 secs | 1.5 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.85 secs | 1.58333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.85 secs | 1.66666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.87 secs | 1.75 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.87 secs | 1.83333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.87 secs | 1.91666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.88 secs | 2 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.9 secs | 2 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:36 | total elpsd: 0.9 secs | 2 fireSpread stats 5"
## [1] "2019-11-27 09:15:36 | total elpsd: 0.91 secs | 2 save spades 10"
## simList saved in
##  SpaDES.core:::.pkgEnv$.sim 
## It will be deleted at next spades() call.
## [1] "2019-11-27 09:15:36 | total elpsd: 0.0013 secs | 0 checkpoint init 0"
## [1] "2019-11-27 09:15:36 | total elpsd: 0.0024 secs | 0 save init 0"
## [1] "2019-11-27 09:15:36 | total elpsd: 0.0034 secs | 0 progress init 0"
## [1] "2019-11-27 09:15:36 | total elpsd: 0.0044 secs | 0 load init 0"
## [1] "2019-11-27 09:15:36 | total elpsd: 0.0044 secs | 0 randomLandscapes init 1"
## [1] "2019-11-27 09:15:37 | total elpsd: 0.74 secs | 0 fireSpread init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$startTime, "fireSpread", 
##     "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.74 secs | 0 caribouMovement init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$moveInitialTime, "caribouMovement", 
##     "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.76 secs | 1 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$returnInterval, 
##     "fireSpread", "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.76 secs | 1 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.77 secs | 1 fireSpread stats 5"
## [1] "2019-11-27 09:15:37 | total elpsd: 0.77 secs | 1.08333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.79 secs | 1.16666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.79 secs | 1.25 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.81 secs | 1.33333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.81 secs | 1.41666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.82 secs | 1.5 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.82 secs | 1.58333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.85 secs | 1.66666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.85 secs | 1.75 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.85 secs | 1.83333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.86 secs | 1.91666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.86 secs | 2 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.88 secs | 2 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:37 | total elpsd: 0.89 secs | 2 fireSpread stats 5"
## [1] "2019-11-27 09:15:37 | total elpsd: 0.89 secs | 2 save spades 10"
## simList saved in
##  SpaDES.core:::.pkgEnv$.sim 
## It will be deleted at next spades() call.
## shutting down parallel nodes
##    user  system elapsed 
##    2.19    0.36    2.78
# internal -- second time faster
system.time({
  sims2 <- experiment(mySim, replicates = 2, cache = TRUE, .plotInitialTime = NA)
})
##   loading cached result from previous spades call, adding to memoised copy
##   loading cached result from previous spades call, adding to memoised copy
## shutting down parallel nodes
##    user  system elapsed 
##    0.11    0.05    0.15
all.equal(sims1, sims2)
## [1] TRUE

Wrapping experiment with Cache

Here, the simList (and other arguments to experiment) is hashed once, and if it is found to be the same as previous, then the returned list of simList objects is recovered. This means that even a very large experiment, with many replicates and combinations of parameters and modules can be recovered very quickly. Here we show that you can output objects to disk, so the list of simList objects doesn’t get too big. Then, when we recover it in the Cached version, all the files are still there, the list of simList objects is small, so very fast to recover.

# External
outputs(mySim) <- data.frame(objectName = "landscape")
system.time({
  sims3 <- Cache(experiment, mySim, replicates = 3, .plotInitialTime = NA,
                 clearSimEnv = TRUE)
})
## [1] "2019-11-27 09:15:38 | total elpsd: 0 secs | 0 checkpoint init 0"
## [1] "2019-11-27 09:15:38 | total elpsd: 0 secs | 0 save init 0"
## [1] "2019-11-27 09:15:38 | total elpsd: 0 secs | 0 progress init 0"
## [1] "2019-11-27 09:15:38 | total elpsd: 0 secs | 0 load init 0"
## [1] "2019-11-27 09:15:38 | total elpsd: 0 secs | 0 randomLandscapes init 1"
## [1] "2019-11-27 09:15:39 | total elpsd: 0.73 secs | 0 fireSpread init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$startTime, "fireSpread", 
##     "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.73 secs | 0 caribouMovement init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$moveInitialTime, "caribouMovement", 
##     "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.73 secs | 1 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$returnInterval, 
##     "fireSpread", "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.75 secs | 1 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.75 secs | 1 fireSpread stats 5"
## [1] "2019-11-27 09:15:39 | total elpsd: 0.76 secs | 1.08333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.76 secs | 1.16666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.76 secs | 1.25 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.78 secs | 1.33333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.78 secs | 1.41666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.8 secs | 1.5 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.8 secs | 1.58333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.81 secs | 1.66666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.81 secs | 1.75 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.83 secs | 1.83333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.83 secs | 1.91666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.84 secs | 2 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.86 secs | 2 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:39 | total elpsd: 0.86 secs | 2 fireSpread stats 5"
## [1] "2019-11-27 09:15:39 | total elpsd: 0.86 secs | 2 save spades 10"
## simList saved in
##  SpaDES.core:::.pkgEnv$.sim 
## It will be deleted at next spades() call.
## [1] "2019-11-27 09:15:39 | total elpsd: 0 secs | 0 checkpoint init 0"
## [1] "2019-11-27 09:15:39 | total elpsd: 0 secs | 0 save init 0"
## [1] "2019-11-27 09:15:39 | total elpsd: 0 secs | 0 progress init 0"
## [1] "2019-11-27 09:15:39 | total elpsd: 0 secs | 0 load init 0"
## [1] "2019-11-27 09:15:39 | total elpsd: 0 secs | 0 randomLandscapes init 1"
## [1] "2019-11-27 09:15:40 | total elpsd: 0.72 secs | 0 fireSpread init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$startTime, "fireSpread", 
##     "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.74 secs | 0 caribouMovement init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$moveInitialTime, "caribouMovement", 
##     "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.75 secs | 1 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$returnInterval, 
##     "fireSpread", "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.75 secs | 1 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.77 secs | 1 fireSpread stats 5"
## [1] "2019-11-27 09:15:40 | total elpsd: 0.77 secs | 1.08333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.78 secs | 1.16666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.78 secs | 1.25 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.78 secs | 1.33333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.8 secs | 1.41666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.8 secs | 1.5 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.81 secs | 1.58333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.81 secs | 1.66666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.83 secs | 1.75 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.83 secs | 1.83333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.85 secs | 1.91666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.85 secs | 2 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.86 secs | 2 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:40 | total elpsd: 0.89 secs | 2 fireSpread stats 5"
## [1] "2019-11-27 09:15:40 | total elpsd: 0.89 secs | 2 save spades 10"
## simList saved in
##  SpaDES.core:::.pkgEnv$.sim 
## It will be deleted at next spades() call.
## [1] "2019-11-27 09:15:40 | total elpsd: 0 secs | 0 checkpoint init 0"
## [1] "2019-11-27 09:15:40 | total elpsd: 0 secs | 0 save init 0"
## [1] "2019-11-27 09:15:40 | total elpsd: 0 secs | 0 progress init 0"
## [1] "2019-11-27 09:15:40 | total elpsd: 0 secs | 0 load init 0"
## [1] "2019-11-27 09:15:40 | total elpsd: 0 secs | 0 randomLandscapes init 1"
## [1] "2019-11-27 09:15:41 | total elpsd: 0.74 secs | 0 fireSpread init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$startTime, "fireSpread", 
##     "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.75 secs | 0 caribouMovement init 1"
## Called from: scheduleEvent(sim, SpaDES.core::P(sim)$moveInitialTime, "caribouMovement", 
##     "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.75 secs | 1 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$returnInterval, 
##     "fireSpread", "burn")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.76 secs | 1 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.78 secs | 1 fireSpread stats 5"
## [1] "2019-11-27 09:15:41 | total elpsd: 0.79 secs | 1.08333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.79 secs | 1.16666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.79 secs | 1.25 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.79 secs | 1.33333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.81 secs | 1.41666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.81 secs | 1.5 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.83 secs | 1.58333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.83 secs | 1.66666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.84 secs | 1.75 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.84 secs | 1.83333333333333 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.86 secs | 1.91666666666667 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.86 secs | 2 fireSpread burn 5"
## Called from: scheduleEvent(sim, time(sim), "fireSpread", "stats")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.87 secs | 2 caribouMovement move 5"
## Called from: scheduleEvent(sim, time(sim) + SpaDES.core::P(sim)$moveInterval, 
##     "caribouMovement", "move")
## debug: ord <- order(unlist(lapply(sim@events, function(x) x$eventTime)), 
##     unlist(lapply(sim@events, function(x) x$eventPriority)))
## debug: slot(sim, "events") <- sim@events[ord]
## debug: return(invisible(sim))
## [1] "2019-11-27 09:15:41 | total elpsd: 0.89 secs | 2 fireSpread stats 5"
## [1] "2019-11-27 09:15:41 | total elpsd: 0.89 secs | 2 save spades 10"
## simList saved in
##  SpaDES.core:::.pkgEnv$.sim 
## It will be deleted at next spades() call.
## shutting down parallel nodes
##    user  system elapsed 
##    2.58    0.35    3.03

The second time is way faster. We see the output files in the same location.

system.time({
  sims4 <- Cache(experiment, mySim, replicates = 3, .plotInitialTime = NA,
                 clearSimEnv = TRUE)
})
##   loading cached result from previous experiment call, adding to memoised copy
##    user  system elapsed 
##    0.03    0.01    0.05
# test they are all equal
lapply(1:2, function(x) all.equal(sims3[[x]], sims4[[x]])) 
## [[1]]
## [1] TRUE
## 
## [[2]]
## [1] TRUE
dir(outputPath(mySim), recursive = TRUE)
## [1] "experiment.RData"         "rep1/caribou_year2.rds"  
## [3] "rep1/landscape_year2.rds" "rep2/caribou_year2.rds"  
## [5] "rep2/landscape_year2.rds" "rep3/landscape_year2.rds"

Notice that speed up can be enormous; in this case ~100 times faster.

Nested Caching

This is a continuation of the Nested Caching section in the iv-caching vignetted in the SpaDES.core package. - Imagine we have large model, with many modules, with replication and alternative module collections (e.g., alternative fire models) - To run this would have a nested structure with the following functions:

simInit --> many .inputObjects calls

experiment --> many spades calls --> many module calls --> many event calls --> many function calls

Lets say we start to introduce caching to this structure. We start from the “inner” most functions that we could imaging Caching would be useful. Lets say there are some GIS operations, like raster::projectRaster, which operates on an input shapefile. We can Cache the projectRaster call to make this much faster, since it will always be the same result for a given input raster.

If we look back at our structure above, we see that we still have LOTS of places that are not Cached. That means that the experiment call will still spawn many spades calls, which will still spawn many module calls, and many event calls, just to get to the one Cache(projectRaster) call which is Cached. This function will likely be called hundreds of times (because experiment runs the spades call 100 times due to replication). This is good, but Cache does take some time. So, even if Cache(projectRaster) takes only 0.02 seconds, calling it hundreds of times means maybe 4 seconds. If we are doing this for many functions, then this will be too slow.

We can start putting Cache all up the sequence of calls. Unfortunately, the way we use Cache at each of these levels is a bit different, so we need a slightly different approach for each.

Cache the experiment call

Cache(experiment)

This will assess the simList (the objects, times, modules, etc.) and if they are all the same, it will return the final list of simLists that came from the first experiment call. NOTE: because this can be large, it is likely that you want clearSimEnv = TRUE, and have all objects that are needed after the experiment call saved to disk. Any stochasticity/randomness inside modules will be frozen. This is likely ok if the objective is to show results in a web app (via shiny or otherwise) or another visualization about the experiment outputs, e.g., comparing treatments, once sufficient stochasticity has been achieved.

mySimListOut <- Cache(experiment, mySim, clearSimEnv = TRUE)

Cache the spades calls inside experiment

experiment(cache = TRUE)

This will cache each of the spades calls inside the experiment call. That means that there are as many cache events as there are replicates and experimental treatments, which, again could be a lot. Like caching the experiment call, stochasticity/randomness will be frozen. Note, one good use of this is when you are making iterative, incremental replication, e.g.,

mySimOut <- experiment(mySim, replicates = 5, cache = TRUE)

You decide after waiting 10 minutes for it to finish, that you need more replication. Rather than start from zero replicates, you can just pick up where you left off:

mySimOut <- experiment(mySim, replicates = 10, cache = TRUE)

This will only add 5 more replicates.