R Under development (unstable) (2025-06-04 r88278 ucrt) -- "Unsuffered Consequences" Copyright (C) 2025 The R Foundation for Statistical Computing Platform: x86_64-w64-mingw32/x64 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. > ## This runs testme test script inst/testme/test-capture_journals.R > ## Don't edit - it was autogenerated by inst/testme/deploy.R > future:::testme("capture_journals") Test 'capture_journals' ... Sourcing 9 prologue scripts ... 01/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/001.load.R' 02/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/002.record-state.R' 03/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/030.imports.R' 04/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/050.utils.R' 05/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/090.context.R' 06/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/090.options.R' 07/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/091.envvars.R' 08/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/099.future-setup.R' 09/09 prologue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_prologue/995.detrius-connections.R' Sourcing 9 prologue scripts ... done Running test script: 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/test-capture_journals.R' > library(future) [05:57:21.430] Option 'future.startup.script': TRUE [05:57:21.431] Future startup scripts considered: '.future.R', '~/.future.R' [05:57:21.432] Future startup scripts found: > capture_journals <- future:::capture_journals > message("*** capture_journals() ...") *** capture_journals() ... > slow_fcn <- function(x) { + Sys.sleep(0.01 * (1 + 1/x)) + } > plan(multisession, workers = 2) [05:57:21.434] plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:21.435] | plan(): plan_set(<1 strategies>, skip = FALSE, cleanup = NA, init = TRUE) ... [05:57:21.435] | : all.equal() for FutureStrategyList ... [05:57:21.436] | : . New stack: [05:57:21.436] | : . List of 1 [05:57:21.436] | : . $ :function (..., workers = 2, envir = parent.frame()) [05:57:21.436] | : . ..- attr(*, "class")= chr [1:6] "tweaked" "multisession" "cluster" "multiprocess" ... [05:57:21.436] | : . ..- attr(*, "init")= logi TRUE [05:57:21.436] | : . ..- attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:21.436] | : . gc = FALSE, earlySignal = FALSE, ...) [05:57:21.436] | : . .. ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.436] | : . ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.436] | : . ..- attr(*, "untweakable")= chr "persistent" [05:57:21.436] | : . ..- attr(*, "tweaks")=List of 1 [05:57:21.436] | : . .. ..$ workers: num 2 [05:57:21.436] | : . ..- attr(*, "call")= language plan(multisession, workers = 2) [05:57:21.436] | : . - attr(*, "class")= chr [1:2] "FutureStrategyList" "list" [05:57:21.443] | : . Old stack: [05:57:21.443] | : . List of 1 [05:57:21.443] | : . $ :function (..., gc = FALSE, earlySignal = FALSE, envir = parent.frame()) [05:57:21.443] | : . ..- attr(*, "class")= chr [1:4] "sequential" "uniprocess" "future" "function" [05:57:21.443] | : . ..- attr(*, "init")= logi TRUE [05:57:21.443] | : . ..- attr(*, "factory")=function (..., maxSizeOfObjects = +Inf) [05:57:21.443] | : . .. ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:21.443] | : . ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:21.443] | : . ..- attr(*, "call")= language plan(sequential) [05:57:21.443] | : . - attr(*, "class")= chr [1:2] "FutureStrategyList" "list" [05:57:21.446] | : . Not identical [05:57:21.446] | : . all.equal() for future ... [05:57:21.446] | : . ' List of 2 [05:57:21.446] | : . ' $ target :function (..., workers = 2, envir = parent.frame()) [05:57:21.446] | : . ' ..- attr(*, "class")= chr [1:6] "tweaked" "multisession" "cluster" "multiprocess" ... [05:57:21.446] | : . ' ..- attr(*, "init")= logi TRUE [05:57:21.446] | : . ' ..- attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:21.446] | : . ' gc = FALSE, earlySignal = FALSE, ...) [05:57:21.446] | : . ' .. ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.446] | : . ' ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.446] | : . ' ..- attr(*, "untweakable")= chr "persistent" [05:57:21.446] | : . ' ..- attr(*, "tweaks")=List of 1 [05:57:21.446] | : . ' .. ..$ workers: num 2 [05:57:21.446] | : . ' ..- attr(*, "call")= language plan(multisession, workers = 2) [05:57:21.446] | : . ' $ current:function (..., gc = FALSE, earlySignal = FALSE, envir = parent.frame()) [05:57:21.446] | : . ' ..- attr(*, "class")= chr [1:4] "sequential" "uniprocess" "future" "function" [05:57:21.446] | : . ' ..- attr(*, "init")= logi TRUE [05:57:21.446] | : . ' ..- attr(*, "factory")=function (..., maxSizeOfObjects = +Inf) [05:57:21.446] | : . ' .. ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:21.446] | : . ' ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:21.446] | : . ' ..- attr(*, "call")= language plan(sequential) [05:57:21.455] | : . ' Formals differ [05:57:21.455] | : . all.equal() for future ... done [05:57:21.456] | : . Future strategies differ at level 1 [05:57:21.456] | : all.equal() for FutureStrategyList ... done [05:57:21.456] | : plan(): Setting new future backend stack: [05:57:21.456] | : List of future strategies: [05:57:21.456] | : 1. multisession: [05:57:21.456] | : - args: function (..., workers = 2, envir = parent.frame()) [05:57:21.456] | : - tweaked: TRUE [05:57:21.456] | : - call: plan(multisession, workers = 2) [05:57:21.457] | : List of 1 [05:57:21.457] | : $ :function (..., workers = 2, envir = parent.frame()) [05:57:21.457] | : ..- attr(*, "class")= chr [1:6] "tweaked" "multisession" "cluster" "multiprocess" ... [05:57:21.457] | : ..- attr(*, "init")= logi TRUE [05:57:21.457] | : ..- attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:21.457] | : gc = FALSE, earlySignal = FALSE, ...) [05:57:21.457] | : .. ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.457] | : ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.457] | : ..- attr(*, "untweakable")= chr "persistent" [05:57:21.457] | : ..- attr(*, "tweaks")=List of 1 [05:57:21.457] | : .. ..$ workers: num 2 [05:57:21.457] | : ..- attr(*, "call")= language plan(multisession, workers = 2) [05:57:21.457] | : - attr(*, "class")= chr [1:2] "FutureStrategyList" "list" [05:57:21.461] | : plan(): plan_cleanup('sequential', 'uniprocess', 'future', 'function', cleanup = NA) ... [05:57:21.461] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:21.461] | : . ' Getting current ("next") strategy: 'FutureStrategy', 'sequential', 'uniprocess', 'future', 'function' [05:57:21.462] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:21.462] | : . Legacy shutdown of cluster workers ... [05:57:21.462] | : . ' Stopping existing cluster ... [05:57:21.462] | : . ' , No pre-existing cluster. Skipping [05:57:21.463] | : . ' Stopping existing cluster ... done [05:57:21.463] | : . Legacy shutdown of cluster workers ... done [05:57:21.463] | : plan(): plan_cleanup('sequential', 'uniprocess', 'future', 'function', cleanup = NA) ... done [05:57:21.463] | : plan(): plan_init() of 'tweaked', 'multisession', 'cluster', 'multiprocess', 'future', 'function' ... [05:57:21.463] | : . function (..., workers = 2, envir = parent.frame()) [05:57:21.463] | : . - attr(*, "class")= chr [1:6] "tweaked" "multisession" "cluster" "multiprocess" ... [05:57:21.463] | : . - attr(*, "init")= logi TRUE [05:57:21.463] | : . - attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:21.463] | : . gc = FALSE, earlySignal = FALSE, ...) [05:57:21.463] | : . ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.463] | : . - attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:21.463] | : . - attr(*, "untweakable")= chr "persistent" [05:57:21.463] | : . - attr(*, "tweaks")=List of 1 [05:57:21.463] | : . ..$ workers: num 2 [05:57:21.463] | : . - attr(*, "call")= language plan(multisession, workers = 2) [05:57:21.467] | : . init: TRUE [05:57:21.467] | : . makeFutureBackend() ... [05:57:21.467] | : . ' Backend function: <'NULL'> [05:57:21.467] | : . ' Evaluator tweak arguments: [n=1] [05:57:21.468] | : . ' List of 1 [05:57:21.468] | : . ' $ workers: num 2 [05:57:21.468] | : . ' Evaluator formal arguments: [n=1] [05:57:21.469] | : . ' List of 1 [05:57:21.469] | : . ' $ workers: num 2 [05:57:21.469] | : . ' Backend factory arguments: [n=1] [05:57:21.470] | : . ' Dotted pair list of 1 [05:57:21.470] | : . ' $ workers: num 2 [05:57:21.470] | : . ' MultisessionFutureBackend(workers = , interrupts = TRUE, ...) ... [05:57:21.471] | : . ' , Arguments: [05:57:21.471] | : . ' , List of 5 [05:57:21.471] | : . ' , $ workers : num 2 [05:57:21.471] | : . ' , $ rscript_libs: chr [1:2] "D:/temp/2025_06_05_05_55_16_20588/RtmpCKyFxh/RLIBS_1418c4def7e89" "D:/RCompile/recent/R/library" [05:57:21.471] | : . ' , $ interrupts : logi TRUE [05:57:21.471] | : . ' , $ gc : logi FALSE [05:57:21.471] | : . ' , $ earlySignal : logi FALSE [05:57:21.473] | : . ' , ClusterFutureBackend(..., persistent = FALSE, gc = FALSE, earlySignal = FALSE) ... [05:57:21.473] | : . ' , ; workers: 2 [05:57:21.474] | : . ' , ; getCluster() ... [05:57:21.474] | : . ' , ; getCluster() ... done [05:57:21.474] | : . ' , ; Stopping existing cluster ... [05:57:21.474] | : . ' , ; ` No pre-existing cluster. Skipping [05:57:21.474] | : . ' , ; Stopping existing cluster ... done [05:57:21.474] | : . ' , ; Starting new cluster ... [05:57:21.475] | : . ' , ; ` makeCluster(workers, ...) ... [05:57:21.475] | : . ' , ; ` | Arguments: [05:57:21.475] | : . ' , ; ` | List of 2 [05:57:21.475] | : . ' , ; ` | $ : int 2 [05:57:21.475] | : . ' , ; ` | $ rscript_libs: chr [1:2] "D:/temp/2025_06_05_05_55_16_20588/RtmpCKyFxh/RLIBS_1418c4def7e89" "D:/RCompile/recent/R/library" [05:57:21.477] | : . ' , ; ` | .makeCluster() ... [05:57:21.477] | : . ' , ; ` | : workers: '2' [05:57:21.478] | : . ' , ; ` | : R_FUTURE_PLAN: NA [05:57:21.478] | : . ' , ; ` | : parallelly::makeClusterPSOCK() arguments: [05:57:21.478] | : . ' , ; ` | : List of 2 [05:57:21.478] | : . ' , ; ` | : $ : int 2 [05:57:21.478] | : . ' , ; ` | : $ rscript_libs: chr [1:2] "D:/temp/2025_06_05_05_55_16_20588/RtmpCKyFxh/RLIBS_1418c4def7e89" "D:/RCompile/recent/R/library" [05:57:22.254] | : . ' , ; ` | : Generated cluster UUID [05:57:22.255] | : . ' , ; ` | : Cluster UUID: '32e65f53c9ff5197fb7411c718da9419' [05:57:22.255] | : . ' , ; ` | : Socket cluster with 2 nodes where 2 nodes are on host 'localhost' (R Under development (unstable) (2025-06-04 r88278 ucrt), platform x86_64-w64-mingw32) [05:57:22.259] | : . ' , ; ` | .makeCluster() ... done [05:57:22.260] | : . ' , ; ` | Socket cluster with 2 nodes where 2 nodes are on host 'localhost' (R Under development (unstable) (2025-06-04 r88278 ucrt), platform x86_64-w64-mingw32) [05:57:22.262] | : . ' , ; ` makeCluster(workers, ...) ... done [05:57:22.263] | : . ' , ; ` Number of workers: 2 [05:57:22.263] | : . ' , ; ` Workers UUID: '32e65f53c9ff5197fb7411c718da9419' [05:57:22.264] | : . ' , ; Starting new cluster ... done [05:57:22.264] | : . ' , ClusterFutureBackend(..., persistent = FALSE, gc = FALSE, earlySignal = FALSE) ... done [05:57:22.264] | : . ' , Backend: <'MultisessionFutureBackend', 'ClusterFutureBackend', 'MultiprocessFutureBackend', 'FutureBackend', 'environment'> [05:57:22.264] | : . ' MultisessionFutureBackend(workers = , interrupts = TRUE, ...) ... done [05:57:22.265] | : . makeFutureBackend() ... done [05:57:22.265] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:22.265] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:22.266] | : . plan(): nbrOfWorkers() = 2 [05:57:22.266] | : plan(): plan_init() of 'tweaked', 'multisession', 'cluster', 'multiprocess', 'future', 'function' ... done [05:57:22.266] | plan(): plan_set(<1 strategies>, skip = FALSE, cleanup = NA, init = TRUE) ... done > js <- capture_journals({ + fs <- lapply(3:1, FUN = function(x) future(slow_fcn(x))) + vs <- value(fs) + }) [05:57:22.267] | future(..., label = NULL) ... [05:57:22.267] | : lazy: FALSE [05:57:22.267] | : stdout: TRUE [05:57:22.268] | : conditions: [n=1] 'condition' [05:57:22.268] | : gc: FALSE [05:57:22.268] | : earlySignal: FALSE [05:57:22.269] | : getGlobalsAndPackages() ... [05:57:22.269] | : . Searching for globals ... [05:57:22.306] | : . ' globals found: [8] 'slow_fcn', 'x', '{', 'Sys.sleep', '*', '(', '+', '/' [05:57:22.306] | : . Searching for globals ... done [05:57:22.307] | : . Resolving globals: FALSE [05:57:22.307] | : . Search for packages associated with the globals ... [05:57:22.308] | : . ' Packages associated with globals: [1] 'base' [05:57:22.309] | : . ' Packages: [1] 'base' [05:57:22.309] | : . Search for packages associated with the globals ... done [05:57:22.310] | : . Packages after dropping 'base': [0] [05:57:22.310] | : . globals: [2] 'slow_fcn', 'x' [05:57:22.310] | : . packages: [0] [05:57:22.311] | : getGlobalsAndPackages() ... done [05:57:22.313] | : run() for 'Future' () ... [05:57:22.313] | : . state: 'created' [05:57:22.314] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:22.314] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:22.314] | : . Using MultisessionFutureBackend ... [05:57:22.315] | : . ' Number of futures since start: 0 (0 created, 0 launched, 0 finished) [05:57:22.315] | : . ' Launching futures ... [05:57:22.316] | : . ' , launchFuture() for ClusterFutureBackend ... [05:57:22.316] | : . ' , ; Workers: [n=2] [05:57:22.317] | : . ' , ; Socket cluster with 2 nodes where 2 nodes are on host 'localhost' (R Under development (unstable) (2025-06-04 r88278 ucrt), platform x86_64-w64-mingw32) [05:57:22.320] | : . ' , ; FutureRegistry: 'workers-32e65f53c9ff5197fb7411c718da9419' [05:57:22.320] | : . ' , ; requestWorker() ... [05:57:22.321] | : . ' , ; ` requestNode() ... [05:57:22.321] | : . ' , ; ` | Number of workers: 2 [05:57:22.321] | : . ' , ; ` | Polling for a free worker ... [05:57:22.322] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.322] | : . ' , ; ` | : . Created empty registry 'workers-32e65f53c9ff5197fb7411c718da9419' [05:57:22.322] | : . ' , ; ` | : . Listing all futures [05:57:22.323] | : . ' , ; ` | : . Number of registered futures: 0 [05:57:22.323] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.323] | : . ' , ; ` | : Total time: 0 [05:57:22.324] | : . ' , ; ` | Polling for a free worker ... done [05:57:22.324] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.324] | : . ' , ; ` | : Listing all futures [05:57:22.324] | : . ' , ; ` | : Number of registered futures: 0 [05:57:22.325] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.325] | : . ' , ; ` | avail: [n=2] '1', '2' [05:57:22.325] | : . ' , ; ` | Index of first available worker: 1 [05:57:22.326] | : . ' , ; ` | Validate that the worker is functional ... [05:57:22.522] | : . ' , ; ` | : Worker is functional [05:57:22.523] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.523] | : . ' , ; ` | : . Listing all futures [05:57:22.524] | : . ' , ; ` | : . Number of registered futures: 0 [05:57:22.524] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.524] | : . ' , ; ` | Validate that the worker is functional ... done [05:57:22.524] | : . ' , ; ` requestNode() ... done [05:57:22.526] | : . ' , ; ` cluster node index: 1 [05:57:22.526] | : . ' , ; requestWorker() ... done [05:57:22.527] | : . ' , ; eraseGlobalEnvironment() ... [05:57:22.529] | : . ' , ; eraseGlobalEnvironment() ... done [05:57:22.529] | : . ' , ; launchFuture() ... [05:57:22.529] | : . ' , ; ` cluster node index: 1 [05:57:22.530] | : . ' , ; ` getFutureData() ... [05:57:22.530] | : . ' , ; ` | getFutureCore() ... [05:57:22.530] | : . ' , ; ` | : Packages needed by the future expression (n = 0): [05:57:22.531] | : . ' , ; ` | getFutureCore() ... done [05:57:22.531] | : . ' , ; ` | getFutureCapture() ... [05:57:22.531] | : . ' , ; ` | getFutureCapture() ... done [05:57:22.532] | : . ' , ; ` | getFutureContext() ... [05:57:22.532] | : . ' , ; ` | : plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:22.532] | : . ' , ; ` | : . Getting stack without first backend: [n=0] [05:57:22.533] | : . ' , ; ` | : plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:22.533] | : . ' , ; ` | : Packages needed by future backend (n = 0): [05:57:22.533] | : . ' , ; ` | getFutureContext() ... done [05:57:22.534] | : . ' , ; ` getFutureData() ... done [05:57:22.535] | : . ' , ; ` FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'add', earlySignal = 0) ... [05:57:22.535] | : . ' , ; ` | Appended future to position #1 [05:57:22.535] | : . ' , ; ` | Number of registered futures: 1 [05:57:22.536] | : . ' , ; ` FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'add', earlySignal = 0) ... done [05:57:22.536] | : . ' , ; launchFuture() ... done [05:57:22.536] | : . ' , ; MultisessionFuture started [05:57:22.536] | : . ' , launchFuture() for ClusterFutureBackend ... done [05:57:22.537] | : . ' Launching futures ... done [05:57:22.537] | : . ' Future launched: 'MultisessionFuture', 'ClusterFuture', 'MultiprocessFuture', 'Future' [05:57:22.537] | : . Using MultisessionFutureBackend ... done [05:57:22.538] | : run() for 'Future' () ... done [05:57:22.539] | future(..., label = NULL) ... done [05:57:22.542] | future(..., label = NULL) ... [05:57:22.542] | : lazy: FALSE [05:57:22.542] | : stdout: TRUE [05:57:22.542] | : conditions: [n=1] 'condition' [05:57:22.543] | : gc: FALSE [05:57:22.543] | : earlySignal: FALSE [05:57:22.543] | : getGlobalsAndPackages() ... [05:57:22.544] | : . Searching for globals ... [05:57:22.572] | : . ' globals found: [8] 'slow_fcn', 'x', '{', 'Sys.sleep', '*', '(', '+', '/' [05:57:22.572] | : . Searching for globals ... done [05:57:22.572] | : . Resolving globals: FALSE [05:57:22.573] | : . Search for packages associated with the globals ... [05:57:22.573] | : . ' Packages associated with globals: [1] 'base' [05:57:22.574] | : . ' Packages: [1] 'base' [05:57:22.574] | : . Search for packages associated with the globals ... done [05:57:22.574] | : . Packages after dropping 'base': [0] [05:57:22.575] | : . globals: [2] 'slow_fcn', 'x' [05:57:22.575] | : . packages: [0] [05:57:22.575] | : getGlobalsAndPackages() ... done [05:57:22.576] | : run() for 'Future' () ... [05:57:22.577] | : . state: 'created' [05:57:22.577] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:22.577] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:22.577] | : . Using MultisessionFutureBackend ... [05:57:22.578] | : . ' Number of futures since start: 1 (1 created, 1 launched, 0 finished) [05:57:22.578] | : . ' Launching futures ... [05:57:22.578] | : . ' , launchFuture() for ClusterFutureBackend ... [05:57:22.578] | : . ' , ; Workers: [n=2] [05:57:22.579] | : . ' , ; Socket cluster with 2 nodes where 2 nodes are on host 'localhost' (R Under development (unstable) (2025-06-04 r88278 ucrt), platform x86_64-w64-mingw32) [05:57:22.582] | : . ' , ; FutureRegistry: 'workers-32e65f53c9ff5197fb7411c718da9419' [05:57:22.582] | : . ' , ; requestWorker() ... [05:57:22.582] | : . ' , ; ` requestNode() ... [05:57:22.582] | : . ' , ; ` | Number of workers: 2 [05:57:22.583] | : . ' , ; ` | Polling for a free worker ... [05:57:22.583] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.583] | : . ' , ; ` | : . Listing all futures [05:57:22.583] | : . ' , ; ` | : . Number of registered futures: 1 [05:57:22.584] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.584] | : . ' , ; ` | : Total time: 0 [05:57:22.584] | : . ' , ; ` | Polling for a free worker ... done [05:57:22.584] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.585] | : . ' , ; ` | : Listing all futures [05:57:22.585] | : . ' , ; ` | : Number of registered futures: 1 [05:57:22.585] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.585] | : . ' , ; ` | avail: [n=2] '2' [05:57:22.586] | : . ' , ; ` | Index of first available worker: 2 [05:57:22.586] | : . ' , ; ` | Validate that the worker is functional ... [05:57:22.784] | : . ' , ; ` | : Worker is functional [05:57:22.785] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.785] | : . ' , ; ` | : . Listing all futures [05:57:22.786] | : . ' , ; ` | : . Number of registered futures: 1 [05:57:22.786] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.786] | : . ' , ; ` | Validate that the worker is functional ... done [05:57:22.787] | : . ' , ; ` requestNode() ... done [05:57:22.789] | : . ' , ; ` cluster node index: 2 [05:57:22.789] | : . ' , ; requestWorker() ... done [05:57:22.789] | : . ' , ; eraseGlobalEnvironment() ... [05:57:22.791] | : . ' , ; eraseGlobalEnvironment() ... done [05:57:22.792] | : . ' , ; launchFuture() ... [05:57:22.792] | : . ' , ; ` cluster node index: 2 [05:57:22.792] | : . ' , ; ` getFutureData() ... [05:57:22.793] | : . ' , ; ` | getFutureCore() ... [05:57:22.793] | : . ' , ; ` | : Packages needed by the future expression (n = 0): [05:57:22.793] | : . ' , ; ` | getFutureCore() ... done [05:57:22.794] | : . ' , ; ` | getFutureCapture() ... [05:57:22.794] | : . ' , ; ` | getFutureCapture() ... done [05:57:22.794] | : . ' , ; ` | getFutureContext() ... [05:57:22.795] | : . ' , ; ` | : plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:22.795] | : . ' , ; ` | : . Getting stack without first backend: [n=0] [05:57:22.795] | : . ' , ; ` | : plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:22.796] | : . ' , ; ` | : Packages needed by future backend (n = 0): [05:57:22.796] | : . ' , ; ` | getFutureContext() ... done [05:57:22.797] | : . ' , ; ` getFutureData() ... done [05:57:22.797] | : . ' , ; ` FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'add', earlySignal = 0) ... [05:57:22.803] | : . ' , ; ` | Appended future to position #2 [05:57:22.804] | : . ' , ; ` | Number of registered futures: 2 [05:57:22.804] | : . ' , ; ` FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'add', earlySignal = 0) ... done [05:57:22.804] | : . ' , ; launchFuture() ... done [05:57:22.805] | : . ' , ; MultisessionFuture started [05:57:22.805] | : . ' , launchFuture() for ClusterFutureBackend ... done [05:57:22.805] | : . ' Launching futures ... done [05:57:22.806] | : . ' Future launched: 'MultisessionFuture', 'ClusterFuture', 'MultiprocessFuture', 'Future' [05:57:22.806] | : . Using MultisessionFutureBackend ... done [05:57:22.806] | : run() for 'Future' () ... done [05:57:22.808] | future(..., label = NULL) ... done [05:57:22.808] | future(..., label = NULL) ... [05:57:22.809] | : lazy: FALSE [05:57:22.809] | : stdout: TRUE [05:57:22.809] | : conditions: [n=1] 'condition' [05:57:22.810] | : gc: FALSE [05:57:22.810] | : earlySignal: FALSE [05:57:22.810] | : getGlobalsAndPackages() ... [05:57:22.811] | : . Searching for globals ... [05:57:22.836] | : . ' globals found: [8] 'slow_fcn', 'x', '{', 'Sys.sleep', '*', '(', '+', '/' [05:57:22.836] | : . Searching for globals ... done [05:57:22.837] | : . Resolving globals: FALSE [05:57:22.837] | : . Search for packages associated with the globals ... [05:57:22.838] | : . ' Packages associated with globals: [1] 'base' [05:57:22.839] | : . ' Packages: [1] 'base' [05:57:22.839] | : . Search for packages associated with the globals ... done [05:57:22.840] | : . Packages after dropping 'base': [0] [05:57:22.840] | : . globals: [2] 'slow_fcn', 'x' [05:57:22.840] | : . packages: [0] [05:57:22.841] | : getGlobalsAndPackages() ... done [05:57:22.842] | : run() for 'Future' () ... [05:57:22.842] | : . state: 'created' [05:57:22.843] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:22.843] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:22.843] | : . Using MultisessionFutureBackend ... [05:57:22.844] | : . ' Number of futures since start: 2 (2 created, 2 launched, 0 finished) [05:57:22.844] | : . ' Launching futures ... [05:57:22.844] | : . ' , launchFuture() for ClusterFutureBackend ... [05:57:22.845] | : . ' , ; Workers: [n=2] [05:57:22.845] | : . ' , ; Socket cluster with 2 nodes where 2 nodes are on host 'localhost' (R Under development (unstable) (2025-06-04 r88278 ucrt), platform x86_64-w64-mingw32) [05:57:22.849] | : . ' , ; FutureRegistry: 'workers-32e65f53c9ff5197fb7411c718da9419' [05:57:22.849] | : . ' , ; requestWorker() ... [05:57:22.850] | : . ' , ; ` requestNode() ... [05:57:22.850] | : . ' , ; ` | Number of workers: 2 [05:57:22.850] | : . ' , ; ` | Polling for a free worker ... [05:57:22.851] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.851] | : . ' , ; ` | : . Listing all futures [05:57:22.851] | : . ' , ; ` | : . Number of registered futures: 2 [05:57:22.852] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.852] | : . ' , ; ` | : Poll #1 (0): usedNodes() = 2, workers = 2 [05:57:22.870] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'collect-first', earlySignal = 1) ... [05:57:22.870] | : . ' , ; ` | : . collectValues('workers-32e65f53c9ff5197fb7411c718da9419', firstOnly = TRUE) ... [05:57:22.871] | : . ' , ; ` | : . ' resolved() for MultisessionFuture () ... [05:57:22.872] | : . ' , ; ` | : . ' , Cluster node socket connection: index=4, id=276 [05:57:22.873] | : . ' , ; ` | : . ' , assertValidConnection() ... [05:57:22.873] | : . ' , ; ` | : . ' , ; cluster node index: 1 [05:57:22.874] | : . ' , ; ` | : . ' , assertValidConnection() ... done [05:57:22.875] | : . ' , ; ` | : . ' , receiveMessageFromWorker() for ClusterFuture ... [05:57:22.875] | : . ' , ; ` | : . ' , ; cluster node index: 1 [05:57:22.876] | : . ' , ; ` | : . ' , ; [1] TRUE [05:57:22.876] | : . ' , ; ` | : . ' , ; received data: [05:57:22.876] | : . ' , ; ` | : . ' , ; List of 5 [05:57:22.876] | : . ' , ; ` | : . ' , ; $ type : chr "VALUE" [05:57:22.876] | : . ' , ; ` | : . ' , ; $ value :List of 16 [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ value : NULL [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ visible : logi FALSE [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ stdout : chr "" [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ conditions : list() [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ rng : logi FALSE [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ seed : NULL [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ misuseGlobalEnv : NULL [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ misuseConnections :List of 3 [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..$ added : NULL [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..$ removed : NULL [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..$ replaced: NULL [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ misuseDevices : NULL [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ misuseDefaultDevice: list() [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ started : POSIXct[1:1], format: "2025-06-05 05:57:22" [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ finished : POSIXct[1:1], format: "2025-06-05 05:57:22" [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ uuid : chr [1:2] "9e39fe9a437f8a6d2e2455eb610c4bc9" "1" [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ session_uuid : chr "f9ae746c0a766491fbbc6a0a28d4468e" [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..- attr(*, "source")=List of 5 [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. ..$ host : Named chr "CRANWIN3" [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. .. ..- attr(*, "names")= chr "COMPUTERNAME" [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. ..$ info : Named chr [1:9] "Windows" "Server x64" "build 20348" "CRANWIN3" ... [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. .. ..- attr(*, "names")= chr [1:9] "sysname" "release" "version" "nodename" ... [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. ..$ pid : int 64696 [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. ..$ time : POSIXct[1:1], format: "2025-06-05 05:57:22" [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. ..$ random: int 2147483647 [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ r_info :List of 4 [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..$ version :Classes 'R_system_version', 'package_version', 'numeric_version' hidden list of 1 [05:57:22.876] | : . ' , ; ` | : . ' , ; .. .. ..$ : int [1:3] 4 6 0 [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..$ os : chr "windows" [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..$ os_name : chr "Windows" [05:57:22.876] | : . ' , ; ` | : . ' , ; .. ..$ captures_utf8: logi TRUE [05:57:22.876] | : . ' , ; ` | : . ' , ; ..$ version : chr "1.8" [05:57:22.876] | : . ' , ; ` | : . ' , ; ..- attr(*, "class")= chr "FutureResult" [05:57:22.876] | : . ' , ; ` | : . ' , ; $ success: logi TRUE [05:57:22.876] | : . ' , ; ` | : . ' , ; $ time : 'proc_time' Named num [1:5] 0.06 0.03 0.11 NA NA [05:57:22.876] | : . ' , ; ` | : . ' , ; ..- attr(*, "names")= chr [1:5] "user.self" "sys.self" "elapsed" "user.child" ... [05:57:22.876] | : . ' , ; ` | : . ' , ; $ tag : NULL [05:57:22.895] | : . ' , ; ` | : . ' , ; Received FutureResult [05:57:22.896] | : . ' , ; ` | : . ' , ; FutureResult: [05:57:22.896] | : . ' , ; ` | : . ' , ; value: 'NULL' [05:57:22.896] | : . ' , ; ` | : . ' , ; visible: FALSE [05:57:22.896] | : . ' , ; ` | : . ' , ; stdout: character [05:57:22.896] | : . ' , ; ` | : . ' , ; conditions: [n = 0] [05:57:22.896] | : . ' , ; ` | : . ' , ; RNG used: FALSE [05:57:22.896] | : . ' , ; ` | : . ' , ; duration: 0.1027222 secs (started 2025-06-05 05:57:22.537855) [05:57:22.896] | : . ' , ; ` | : . ' , ; version: 1.8 [05:57:22.897] | : . ' , ; ` | : . ' , ; FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'remove', earlySignal = 0) ... [05:57:22.898] | : . ' , ; ` | : . ' , ; ` Removed future from position #1 [05:57:22.898] | : . ' , ; ` | : . ' , ; ` Number of registered futures: 1 [05:57:22.898] | : . ' , ; ` | : . ' , ; FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'remove', earlySignal = 0) ... done [05:57:22.901] | : . ' , ; ` | : . ' , ; Erased future from future backend [05:57:22.901] | : . ' , ; ` | : . ' , ; result() for ClusterFuture ... [05:57:22.901] | : . ' , ; ` | : . ' , ; ` result already collected: FutureResult [05:57:22.901] | : . ' , ; ` | : . ' , ; result() for ClusterFuture ... done [05:57:22.905] | : . ' , ; ` | : . ' , ; signalConditions() ... [05:57:22.905] | : . ' , ; ` | : . ' , ; ` include = 'immediateCondition' [05:57:22.905] | : . ' , ; ` | : . ' , ; ` exclude = [05:57:22.905] | : . ' , ; ` | : . ' , ; ` resignal = FALSE [05:57:22.905] | : . ' , ; ` | : . ' , ; ` Number of conditions: 0 [05:57:22.906] | : . ' , ; ` | : . ' , ; ` int 0 [05:57:22.906] | : . ' , ; ` | : . ' , ; signalConditions() ... done [05:57:22.906] | : . ' , ; ` | : . ' , receiveMessageFromWorker() for ClusterFuture ... done [05:57:22.906] | : . ' , ; ` | : . ' , receiveMessageFromWorker() returned object of class FutureResult; resolved [05:57:22.907] | : . ' , ; ` | : . ' resolved() for MultisessionFuture () ... done [05:57:22.907] | : . ' , ; ` | : . ' assertFutureResult() ... [05:57:22.907] | : . ' , ; ` | : . ' , Future uuid: 9e39fe9a437f8a6d2e2455eb610c4bc9[05:57:22.907] | : . ' , ; ` | : . ' , Future uuid: 1 [05:57:22.907] | : . ' , ; ` | : . ' , identical; success [05:57:22.907] | : . ' , ; ` | : . ' assertFutureResult() ... done [05:57:22.908] | : . ' , ; ` | : . ' Future at position #1 is resolved ... [05:57:22.908] | : . ' , ; ` | : . ' , value() for MultisessionFuture () ... [05:57:22.908] | : . ' , ; ` | : . ' , ; result() for ClusterFuture ... [05:57:22.909] | : . ' , ; ` | : . ' , ; ` result already collected: FutureResult [05:57:22.909] | : . ' , ; ` | : . ' , ; result() for ClusterFuture ... done [05:57:22.909] | : . ' , ; ` | : . ' , ; result() for ClusterFuture ... [05:57:22.909] | : . ' , ; ` | : . ' , ; ` result already collected: FutureResult [05:57:22.909] | : . ' , ; ` | : . ' , ; result() for ClusterFuture ... done [05:57:22.910] | : . ' , ; ` | : . ' , ; signalConditions() ... [05:57:22.910] | : . ' , ; ` | : . ' , ; ` include = 'immediateCondition' [05:57:22.910] | : . ' , ; ` | : . ' , ; ` exclude = [05:57:22.910] | : . ' , ; ` | : . ' , ; ` resignal = FALSE [05:57:22.910] | : . ' , ; ` | : . ' , ; ` Number of conditions: 0 [05:57:22.910] | : . ' , ; ` | : . ' , ; ` int 0 [05:57:22.911] | : . ' , ; ` | : . ' , ; signalConditions() ... done [05:57:22.911] | : . ' , ; ` | : . ' , ; check for misuse ... [05:57:22.911] | : . ' , ; ` | : . ' , ; check for misuse ... done [05:57:22.911] | : . ' , ; ` | : . ' , value() for MultisessionFuture () ... done [05:57:22.912] | : . ' , ; ` | : . ' Future at position #1 is resolved ... done [05:57:22.912] | : . ' , ; ` | : . collectValues('workers-32e65f53c9ff5197fb7411c718da9419', firstOnly = TRUE) ... done [05:57:22.912] | : . ' , ; ` | : . Remove collected futures ... [05:57:22.912] | : . ' , ; ` | : . ' Indices of futures to drop: [n=1] '1' [05:57:22.912] | : . ' , ; ` | : . Remove collected futures ... done [05:57:22.913] | : . ' , ; ` | : FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'collect-first', earlySignal = 1) ... done [05:57:22.913] | : . ' , ; ` | : Early signaling of 2 future candidates ... [05:57:22.913] | : . ' , ; ` | : Number of futures with early signaling requested: 0 [05:57:22.913] | : . ' , ; ` | : Early signaling of 2 future candidates ... done [05:57:22.913] | : . ' , ; ` | : Number of registered futures: 2 [05:57:22.913] | : . ' , ; ` | Polling for a free worker ... done [05:57:22.914] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.914] | : . ' , ; ` | : Listing all futures [05:57:22.914] | : . ' , ; ` | : Number of registered futures: 1 [05:57:22.914] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.914] | : . ' , ; ` | Total time: 0.0628571510314941 [05:57:22.914] | : . ' , ; ` requestNode() ... done [05:57:22.915] | : . ' , ; ` FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.915] | : . ' , ; ` | Listing all futures [05:57:22.915] | : . ' , ; ` | Number of registered futures: 1 [05:57:22.915] | : . ' , ; ` FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.915] | : . ' , ; ` avail: [n=2] '1' [05:57:22.915] | : . ' , ; ` Index of first available worker: 1 [05:57:22.916] | : . ' , ; ` Validate that the worker is functional ... [05:57:22.993] | : . ' , ; ` | Worker is functional [05:57:22.994] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... [05:57:22.994] | : . ' , ; ` | : Listing all futures [05:57:22.994] | : . ' , ; ` | : Number of registered futures: 1 [05:57:22.995] | : . ' , ; ` | FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'list', earlySignal = 0) ... done [05:57:22.995] | : . ' , ; ` Validate that the worker is functional ... done [05:57:22.995] | : . ' , ; requestWorker() ... done [05:57:22.997] | : . ' , ; cluster node index: 1 [05:57:22.997] | : . ' , launchFuture() for ClusterFutureBackend ... done [05:57:22.997] | : . ' , eraseGlobalEnvironment() ... [05:57:22.999] | : . ' , eraseGlobalEnvironment() ... done [05:57:23.000] | : . ' , launchFuture() ... [05:57:23.000] | : . ' , ; cluster node index: 1 [05:57:23.000] | : . ' , ; getFutureData() ... [05:57:23.001] | : . ' , ; ` getFutureCore() ... [05:57:23.001] | : . ' , ; ` | Packages needed by the future expression (n = 0): [05:57:23.001] | : . ' , ; ` getFutureCore() ... done [05:57:23.002] | : . ' , ; ` getFutureCapture() ... [05:57:23.002] | : . ' , ; ` getFutureCapture() ... done [05:57:23.002] | : . ' , ; ` getFutureContext() ... [05:57:23.002] | : . ' , ; ` | plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:23.003] | : . ' , ; ` | : Getting stack without first backend: [n=0] [05:57:23.003] | : . ' , ; ` | plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:23.003] | : . ' , ; ` | Packages needed by future backend (n = 0): [05:57:23.003] | : . ' , ; ` getFutureContext() ... done [05:57:23.004] | : . ' , ; getFutureData() ... done [05:57:23.004] | : . ' , ; FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'add', earlySignal = 0) ... [05:57:23.005] | : . ' , ; ` Appended future to position #2 [05:57:23.005] | : . ' , ; ` Number of registered futures: 2 [05:57:23.005] | : . ' , ; FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'add', earlySignal = 0) ... done [05:57:23.005] | : . ' , launchFuture() ... done [05:57:23.006] | : . ' , MultisessionFuture started [05:57:23.006] | : . ' Launching futures ... done [05:57:23.006] | : . Using MultisessionFutureBackend ... done [05:57:23.006] | : . Future launched: 'MultisessionFuture', 'ClusterFuture', 'MultiprocessFuture', 'Future' [05:57:23.007] | : run() for 'Future' () ... done [05:57:23.007] | future(..., label = NULL) ... done [05:57:23.008] plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:23.009] value() for list ... [05:57:23.009] | recursive: 0 [05:57:23.009] | reduce: FALSE [05:57:23.010] | length: 3 [05:57:23.010] | Number of remaining objects: 3 [05:57:23.010] | checking value #1: [05:57:23.010] | 'obj' is MultisessionFuture [05:57:23.010] | MultisessionFuture #1 [05:57:23.011] | signalConditionsASAP(MultisessionFuture, pos=1) ... [05:57:23.011] | : nx: 3 [05:57:23.011] | : relay: TRUE [05:57:23.011] | : stdout: TRUE [05:57:23.011] | : signal: TRUE [05:57:23.011] | : resignal: FALSE [05:57:23.012] | : force: TRUE [05:57:23.012] | : relayed: [n=3] FALSE, FALSE, FALSE [05:57:23.012] | : queued futures: [n=3] FALSE, FALSE, FALSE [05:57:23.012] | : until=1 [05:57:23.012] | : relaying element #1 [05:57:23.012] | : value() for MultisessionFuture () ... [05:57:23.013] | : . result() for ClusterFuture ... [05:57:23.013] | : . ' result already collected: FutureResult [05:57:23.013] | : . result() for ClusterFuture ... done [05:57:23.013] | : . result() for ClusterFuture ... [05:57:23.013] | : . ' result already collected: FutureResult [05:57:23.014] | : . result() for ClusterFuture ... done [05:57:23.014] | : . signalConditions() ... [05:57:23.014] | : . ' include = 'immediateCondition' [05:57:23.014] | : . ' exclude = [05:57:23.014] | : . ' resignal = FALSE [05:57:23.014] | : . ' Number of conditions: 0 [05:57:23.015] | : . ' int 0 [05:57:23.015] | : . signalConditions() ... done [05:57:23.015] | : . relay stdout ... [05:57:23.016] | : . relay stdout ... done [05:57:23.016] | : . check for misuse ... [05:57:23.016] | : . check for misuse ... done [05:57:23.016] | : value() for MultisessionFuture () ... done [05:57:23.016] | : result() for ClusterFuture ... [05:57:23.016] | : . result already collected: FutureResult [05:57:23.017] | : result() for ClusterFuture ... done [05:57:23.017] | : signalConditions() ... [05:57:23.017] | : . include = 'immediateCondition' [05:57:23.017] | : . exclude = [05:57:23.017] | : . resignal = FALSE [05:57:23.018] | : . Number of conditions: 0 [05:57:23.018] | : . int 0 [05:57:23.018] | : signalConditions() ... done [05:57:23.018] | : result() for ClusterFuture ... [05:57:23.019] | : . result already collected: FutureResult [05:57:23.019] | : result() for ClusterFuture ... done [05:57:23.019] | : signalConditions() ... [05:57:23.019] | : . include = 'condition' [05:57:23.019] | : . exclude = 'error', 'immediateCondition' [05:57:23.020] | : . resignal = TRUE [05:57:23.020] | : . Number of conditions: 0 [05:57:23.020] | : . int 0 [05:57:23.020] | : signalConditions() ... done [05:57:23.021] | : relayed: [n=3] TRUE, FALSE, FALSE [05:57:23.021] | : queued futures: [n=3] TRUE, FALSE, FALSE [05:57:23.021] | signalConditionsASAP(MultisessionFuture, pos=1) ... done [05:57:23.021] | value(, ...) ... [05:57:23.021] | value(, ...) ... done [05:57:23.021] | value() for MultisessionFuture () ... [05:57:23.022] | : result() for ClusterFuture ... [05:57:23.022] | : . result already collected: FutureResult [05:57:23.022] | : result() for ClusterFuture ... done [05:57:23.022] | : result() for ClusterFuture ... [05:57:23.022] | : . result already collected: FutureResult [05:57:23.023] | : result() for ClusterFuture ... done [05:57:23.023] | : signalConditions() ... [05:57:23.023] | : . include = 'immediateCondition' [05:57:23.023] | : . exclude = [05:57:23.023] | : . resignal = FALSE [05:57:23.023] | : . Number of conditions: 0 [05:57:23.024] | : . int 0 [05:57:23.024] | : signalConditions() ... done [05:57:23.024] | : check for misuse ... [05:57:23.025] | : check for misuse ... done [05:57:23.025] | value() for MultisessionFuture () ... done [05:57:23.025] | value: [05:57:23.025] | signalConditionsASAP(MultisessionFuture, pos=1) ... [05:57:23.025] | : nx: 3 [05:57:23.025] | : relay: TRUE [05:57:23.025] | : stdout: TRUE [05:57:23.026] | : signal: TRUE [05:57:23.026] | : resignal: FALSE [05:57:23.026] | : force: TRUE [05:57:23.026] | : relayed: [n=3] TRUE, FALSE, FALSE [05:57:23.026] | : queued futures: [n=3] TRUE, FALSE, FALSE [05:57:23.026] | : until=2 [05:57:23.027] | : relaying element #2 [05:57:23.027] | : relayed: [n=3] TRUE, FALSE, FALSE [05:57:23.027] | : queued futures: [n=3] TRUE, FALSE, FALSE [05:57:23.027] | signalConditionsASAP(MultisessionFuture, pos=1) ... done [05:57:23.027] | resolve() for MultisessionFuture ... [05:57:23.028] | : length: 2 (resolved future 1) [05:57:23.029] | resolve() for MultisessionFuture ... done [05:57:23.029] | checking value #2: [05:57:23.029] | 'obj' is MultisessionFuture [05:57:23.029] | resolved() for MultisessionFuture () ... [05:57:23.030] | : Cluster node socket connection: index=5, id=277 [05:57:23.030] | : assertValidConnection() ... [05:57:23.030] | : . cluster node index: 2 [05:57:23.030] | : assertValidConnection() ... done [05:57:23.031] | : receiveMessageFromWorker() for ClusterFuture ... [05:57:23.031] | : . cluster node index: 2 [05:57:23.031] | : . [1] TRUE [05:57:23.031] | : . received data: [05:57:23.032] | : . List of 5 [05:57:23.032] | : . $ type : chr "VALUE" [05:57:23.032] | : . $ value :List of 16 [05:57:23.032] | : . ..$ value : NULL [05:57:23.032] | : . ..$ visible : logi FALSE [05:57:23.032] | : . ..$ stdout : chr "" [05:57:23.032] | : . ..$ conditions : list() [05:57:23.032] | : . ..$ rng : logi FALSE [05:57:23.032] | : . ..$ seed : NULL [05:57:23.032] | : . ..$ misuseGlobalEnv : NULL [05:57:23.032] | : . ..$ misuseConnections :List of 3 [05:57:23.032] | : . .. ..$ added : NULL [05:57:23.032] | : . .. ..$ removed : NULL [05:57:23.032] | : . .. ..$ replaced: NULL [05:57:23.032] | : . ..$ misuseDevices : NULL [05:57:23.032] | : . ..$ misuseDefaultDevice: list() [05:57:23.032] | : . ..$ started : POSIXct[1:1], format: "2025-06-05 05:57:22" [05:57:23.032] | : . ..$ finished : POSIXct[1:1], format: "2025-06-05 05:57:22" [05:57:23.032] | : . ..$ uuid : chr [1:2] "9e39fe9a437f8a6d2e2455eb610c4bc9" "2" [05:57:23.032] | : . ..$ session_uuid : chr "99f93726084253d165997ab16dcef300" [05:57:23.032] | : . .. ..- attr(*, "source")=List of 5 [05:57:23.032] | : . .. .. ..$ host : Named chr "CRANWIN3" [05:57:23.032] | : . .. .. .. ..- attr(*, "names")= chr "COMPUTERNAME" [05:57:23.032] | : . .. .. ..$ info : Named chr [1:9] "Windows" "Server x64" "build 20348" "CRANWIN3" ... [05:57:23.032] | : . .. .. .. ..- attr(*, "names")= chr [1:9] "sysname" "release" "version" "nodename" ... [05:57:23.032] | : . .. .. ..$ pid : int 37128 [05:57:23.032] | : . .. .. ..$ time : POSIXct[1:1], format: "2025-06-05 05:57:22" [05:57:23.032] | : . .. .. ..$ random: int 2147483647 [05:57:23.032] | : . ..$ r_info :List of 4 [05:57:23.032] | : . .. ..$ version :Classes 'R_system_version', 'package_version', 'numeric_version' hidden list of 1 [05:57:23.032] | : . .. .. ..$ : int [1:3] 4 6 0 [05:57:23.032] | : . .. ..$ os : chr "windows" [05:57:23.032] | : . .. ..$ os_name : chr "Windows" [05:57:23.032] | : . .. ..$ captures_utf8: logi TRUE [05:57:23.032] | : . ..$ version : chr "1.8" [05:57:23.032] | : . ..- attr(*, "class")= chr "FutureResult" [05:57:23.032] | : . $ success: logi TRUE [05:57:23.032] | : . $ time : 'proc_time' Named num [1:5] 0.11 0 0.12 NA NA [05:57:23.032] | : . ..- attr(*, "names")= chr [1:5] "user.self" "sys.self" "elapsed" "user.child" ... [05:57:23.032] | : . $ tag : NULL [05:57:23.046] | : . Received FutureResult [05:57:23.047] | : . FutureResult: [05:57:23.047] | : . value: 'NULL' [05:57:23.047] | : . visible: FALSE [05:57:23.047] | : . stdout: character [05:57:23.047] | : . conditions: [n = 0] [05:57:23.047] | : . RNG used: FALSE [05:57:23.047] | : . duration: 0.1246309 secs (started 2025-06-05 05:57:22.800101) [05:57:23.047] | : . version: 1.8 [05:57:23.047] | : . FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'remove', earlySignal = 0) ... [05:57:23.048] | : . ' Removed future from position #1 [05:57:23.048] | : . ' Number of registered futures: 1 [05:57:23.048] | : . FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'remove', earlySignal = 0) ... done [05:57:23.048] | : . Erased future from future backend [05:57:23.048] | : . result() for ClusterFuture ... [05:57:23.049] | : . ' result already collected: FutureResult [05:57:23.049] | : . result() for ClusterFuture ... done [05:57:23.052] | : . signalConditions() ... [05:57:23.052] | : . ' include = 'immediateCondition' [05:57:23.052] | : . ' exclude = [05:57:23.052] | : . ' resignal = FALSE [05:57:23.052] | : . ' Number of conditions: 0 [05:57:23.052] | : . ' int 0 [05:57:23.053] | : . signalConditions() ... done [05:57:23.053] | : receiveMessageFromWorker() for ClusterFuture ... done [05:57:23.053] | : receiveMessageFromWorker() returned object of class FutureResult; resolved [05:57:23.054] | resolved() for MultisessionFuture () ... done [05:57:23.054] | assertFutureResult() ... [05:57:23.054] | : Future uuid: 9e39fe9a437f8a6d2e2455eb610c4bc9[05:57:23.054] | : Future uuid: 2 [05:57:23.054] | : identical; success [05:57:23.054] | assertFutureResult() ... done [05:57:23.054] | MultisessionFuture #2 [05:57:23.055] | signalConditionsASAP(MultisessionFuture, pos=2) ... [05:57:23.055] | : nx: 3 [05:57:23.055] | : relay: TRUE [05:57:23.055] | : stdout: TRUE [05:57:23.055] | : signal: TRUE [05:57:23.055] | : resignal: FALSE [05:57:23.056] | : force: TRUE [05:57:23.056] | : relayed: [n=3] TRUE, FALSE, FALSE [05:57:23.056] | : queued futures: [n=3] TRUE, FALSE, FALSE [05:57:23.056] | : until=2 [05:57:23.056] | : relaying element #2 [05:57:23.056] | : value() for MultisessionFuture () ... [05:57:23.057] | : . result() for ClusterFuture ... [05:57:23.057] | : . ' result already collected: FutureResult [05:57:23.057] | : . result() for ClusterFuture ... done [05:57:23.057] | : . result() for ClusterFuture ... [05:57:23.057] | : . ' result already collected: FutureResult [05:57:23.058] | : . result() for ClusterFuture ... done [05:57:23.058] | : . signalConditions() ... [05:57:23.058] | : . ' include = 'immediateCondition' [05:57:23.058] | : . ' exclude = [05:57:23.058] | : . ' resignal = FALSE [05:57:23.058] | : . ' Number of conditions: 0 [05:57:23.059] | : . ' int 0 [05:57:23.059] | : . signalConditions() ... done [05:57:23.059] | : . relay stdout ... [05:57:23.059] | : . relay stdout ... done [05:57:23.060] | : . check for misuse ... [05:57:23.060] | : . check for misuse ... done [05:57:23.060] | : value() for MultisessionFuture () ... done [05:57:23.060] | : result() for ClusterFuture ... [05:57:23.060] | : . result already collected: FutureResult [05:57:23.061] | : result() for ClusterFuture ... done [05:57:23.061] | : signalConditions() ... [05:57:23.061] | : . include = 'immediateCondition' [05:57:23.063] | : . exclude = [05:57:23.064] | : . resignal = FALSE [05:57:23.064] | : . Number of conditions: 0 [05:57:23.064] | : . int 0 [05:57:23.065] | : signalConditions() ... done [05:57:23.065] | : result() for ClusterFuture ... [05:57:23.065] | : . result already collected: FutureResult [05:57:23.065] | : result() for ClusterFuture ... done [05:57:23.065] | : signalConditions() ... [05:57:23.066] | : . include = 'condition' [05:57:23.066] | : . exclude = 'error', 'immediateCondition' [05:57:23.066] | : . resignal = TRUE [05:57:23.066] | : . Number of conditions: 0 [05:57:23.066] | : . int 0 [05:57:23.067] | : signalConditions() ... done [05:57:23.067] | : relayed: [n=3] TRUE, TRUE, FALSE [05:57:23.067] | : queued futures: [n=3] TRUE, TRUE, FALSE [05:57:23.067] | signalConditionsASAP(MultisessionFuture, pos=2) ... done [05:57:23.067] | value(, ...) ... [05:57:23.068] | value(, ...) ... done [05:57:23.068] | value() for MultisessionFuture () ... [05:57:23.068] | : result() for ClusterFuture ... [05:57:23.068] | : . result already collected: FutureResult [05:57:23.068] | : result() for ClusterFuture ... done [05:57:23.068] | : result() for ClusterFuture ... [05:57:23.069] | : . result already collected: FutureResult [05:57:23.069] | : result() for ClusterFuture ... done [05:57:23.069] | : signalConditions() ... [05:57:23.069] | : . include = 'immediateCondition' [05:57:23.069] | : . exclude = [05:57:23.069] | : . resignal = FALSE [05:57:23.070] | : . Number of conditions: 0 [05:57:23.070] | : . int 0 [05:57:23.070] | : signalConditions() ... done [05:57:23.071] | : check for misuse ... [05:57:23.071] | : check for misuse ... done [05:57:23.071] | value() for MultisessionFuture () ... done [05:57:23.071] | value: [05:57:23.071] | signalConditionsASAP(MultisessionFuture, pos=2) ... [05:57:23.071] | : nx: 3 [05:57:23.072] | : relay: TRUE [05:57:23.072] | : stdout: TRUE [05:57:23.072] | : signal: TRUE [05:57:23.072] | : resignal: FALSE [05:57:23.072] | : force: TRUE [05:57:23.072] | : relayed: [n=3] TRUE, TRUE, FALSE [05:57:23.072] | : queued futures: [n=3] TRUE, TRUE, FALSE [05:57:23.073] | : until=3 [05:57:23.073] | : relaying element #3 [05:57:23.073] | : relayed: [n=3] TRUE, TRUE, FALSE [05:57:23.073] | : queued futures: [n=3] TRUE, TRUE, FALSE [05:57:23.073] | signalConditionsASAP(MultisessionFuture, pos=2) ... done [05:57:23.074] | resolve() for MultisessionFuture ... [05:57:23.075] | : length: 1 (resolved future 2) [05:57:23.075] | resolve() for MultisessionFuture ... done [05:57:23.076] | checking value #3: [05:57:23.076] | 'obj' is MultisessionFuture [05:57:23.076] | resolved() for MultisessionFuture () ... [05:57:23.077] | : Cluster node socket connection: index=4, id=276 [05:57:23.077] | : assertValidConnection() ... [05:57:23.077] | : . cluster node index: 1 [05:57:23.078] | : assertValidConnection() ... done [05:57:23.078] | : receiveMessageFromWorker() for ClusterFuture ... [05:57:23.079] | : . cluster node index: 1 [05:57:23.079] | : . [1] TRUE [05:57:23.079] | : . received data: [05:57:23.079] | : . List of 5 [05:57:23.079] | : . $ type : chr "VALUE" [05:57:23.079] | : . $ value :List of 16 [05:57:23.079] | : . ..$ value : NULL [05:57:23.079] | : . ..$ visible : logi FALSE [05:57:23.079] | : . ..$ stdout : chr "" [05:57:23.079] | : . ..$ conditions : list() [05:57:23.079] | : . ..$ rng : logi FALSE [05:57:23.079] | : . ..$ seed : NULL [05:57:23.079] | : . ..$ misuseGlobalEnv : NULL [05:57:23.079] | : . ..$ misuseConnections :List of 3 [05:57:23.079] | : . .. ..$ added : NULL [05:57:23.079] | : . .. ..$ removed : NULL [05:57:23.079] | : . .. ..$ replaced: NULL [05:57:23.079] | : . ..$ misuseDevices : NULL [05:57:23.079] | : . ..$ misuseDefaultDevice: list() [05:57:23.079] | : . ..$ started : POSIXct[1:1], format: "2025-06-05 05:57:23" [05:57:23.079] | : . ..$ finished : POSIXct[1:1], format: "2025-06-05 05:57:23" [05:57:23.079] | : . ..$ uuid : chr [1:2] "9e39fe9a437f8a6d2e2455eb610c4bc9" "3" [05:57:23.079] | : . ..$ session_uuid : chr "f9ae746c0a766491fbbc6a0a28d4468e" [05:57:23.079] | : . .. ..- attr(*, "source")=List of 5 [05:57:23.079] | : . .. .. ..$ host : Named chr "CRANWIN3" [05:57:23.079] | : . .. .. .. ..- attr(*, "names")= chr "COMPUTERNAME" [05:57:23.079] | : . .. .. ..$ info : Named chr [1:9] "Windows" "Server x64" "build 20348" "CRANWIN3" ... [05:57:23.079] | : . .. .. .. ..- attr(*, "names")= chr [1:9] "sysname" "release" "version" "nodename" ... [05:57:23.079] | : . .. .. ..$ pid : int 64696 [05:57:23.079] | : . .. .. ..$ time : POSIXct[1:1], format: "2025-06-05 05:57:22" [05:57:23.079] | : . .. .. ..$ random: int 2147483647 [05:57:23.079] | : . ..$ r_info :List of 4 [05:57:23.079] | : . .. ..$ version :Classes 'R_system_version', 'package_version', 'numeric_version' hidden list of 1 [05:57:23.079] | : . .. .. ..$ : int [1:3] 4 6 0 [05:57:23.079] | : . .. ..$ os : chr "windows" [05:57:23.079] | : . .. ..$ os_name : chr "Windows" [05:57:23.079] | : . .. ..$ captures_utf8: logi TRUE [05:57:23.079] | : . ..$ version : chr "1.8" [05:57:23.079] | : . ..- attr(*, "class")= chr "FutureResult" [05:57:23.079] | : . $ success: logi TRUE [05:57:23.079] | : . $ time : 'proc_time' Named num [1:5] 0 0 0.05 NA NA [05:57:23.079] | : . ..- attr(*, "names")= chr [1:5] "user.self" "sys.self" "elapsed" "user.child" ... [05:57:23.079] | : . $ tag : NULL [05:57:23.095] | : . Received FutureResult [05:57:23.096] | : . FutureResult: [05:57:23.096] | : . value: 'NULL' [05:57:23.096] | : . visible: FALSE [05:57:23.096] | : . stdout: character [05:57:23.096] | : . conditions: [n = 0] [05:57:23.096] | : . RNG used: FALSE [05:57:23.096] | : . duration: 0.03968096 secs (started 2025-06-05 05:57:23.005212) [05:57:23.096] | : . version: 1.8 [05:57:23.097] | : . FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'remove', earlySignal = 0) ... [05:57:23.097] | : . ' Removed future from position #1 [05:57:23.098] | : . ' Number of registered futures: 0 [05:57:23.098] | : . FutureRegistry('workers-32e65f53c9ff5197fb7411c718da9419', action = 'remove', earlySignal = 0) ... done [05:57:23.098] | : . Erased future from future backend [05:57:23.099] | : . result() for ClusterFuture ... [05:57:23.099] | : . ' result already collected: FutureResult [05:57:23.099] | : . result() for ClusterFuture ... done [05:57:23.103] | : . signalConditions() ... [05:57:23.104] | : . ' include = 'immediateCondition' [05:57:23.104] | : . ' exclude = [05:57:23.104] | : . ' resignal = FALSE [05:57:23.104] | : . ' Number of conditions: 0 [05:57:23.105] | : . ' int 0 [05:57:23.106] | : . signalConditions() ... done [05:57:23.106] | : receiveMessageFromWorker() for ClusterFuture ... done [05:57:23.106] | : receiveMessageFromWorker() returned object of class FutureResult; resolved [05:57:23.106] | resolved() for MultisessionFuture () ... done [05:57:23.107] | assertFutureResult() ... [05:57:23.107] | : Future uuid: 9e39fe9a437f8a6d2e2455eb610c4bc9[05:57:23.107] | : Future uuid: 3 [05:57:23.107] | : identical; success [05:57:23.108] | assertFutureResult() ... done [05:57:23.108] | MultisessionFuture #3 [05:57:23.108] | signalConditionsASAP(MultisessionFuture, pos=3) ... [05:57:23.108] | : nx: 3 [05:57:23.109] | : relay: TRUE [05:57:23.109] | : stdout: TRUE [05:57:23.109] | : signal: TRUE [05:57:23.109] | : resignal: FALSE [05:57:23.110] | : force: TRUE [05:57:23.110] | : relayed: [n=3] TRUE, TRUE, FALSE [05:57:23.110] | : queued futures: [n=3] TRUE, TRUE, FALSE [05:57:23.110] | : until=3 [05:57:23.111] | : relaying element #3 [05:57:23.111] | : value() for MultisessionFuture () ... [05:57:23.111] | : . result() for ClusterFuture ... [05:57:23.112] | : . ' result already collected: FutureResult [05:57:23.112] | : . result() for ClusterFuture ... done [05:57:23.112] | : . result() for ClusterFuture ... [05:57:23.113] | : . ' result already collected: FutureResult [05:57:23.113] | : . result() for ClusterFuture ... done [05:57:23.113] | : . signalConditions() ... [05:57:23.113] | : . ' include = 'immediateCondition' [05:57:23.114] | : . ' exclude = [05:57:23.114] | : . ' resignal = FALSE [05:57:23.114] | : . ' Number of conditions: 0 [05:57:23.114] | : . ' int 0 [05:57:23.115] | : . signalConditions() ... done [05:57:23.115] | : . relay stdout ... [05:57:23.116] | : . relay stdout ... done [05:57:23.116] | : . check for misuse ... [05:57:23.116] | : . check for misuse ... done [05:57:23.116] | : value() for MultisessionFuture () ... done [05:57:23.117] | : result() for ClusterFuture ... [05:57:23.117] | : . result already collected: FutureResult [05:57:23.117] | : result() for ClusterFuture ... done [05:57:23.118] | : signalConditions() ... [05:57:23.118] | : . include = 'immediateCondition' [05:57:23.118] | : . exclude = [05:57:23.118] | : . resignal = FALSE [05:57:23.119] | : . Number of conditions: 0 [05:57:23.119] | : . int 0 [05:57:23.120] | : signalConditions() ... done [05:57:23.120] | : result() for ClusterFuture ... [05:57:23.120] | : . result already collected: FutureResult [05:57:23.121] | : result() for ClusterFuture ... done [05:57:23.121] | : signalConditions() ... [05:57:23.121] | : . include = 'condition' [05:57:23.121] | : . exclude = 'error', 'immediateCondition' [05:57:23.122] | : . resignal = TRUE [05:57:23.122] | : . Number of conditions: 0 [05:57:23.122] | : . int 0 [05:57:23.123] | : signalConditions() ... done [05:57:23.123] | : relayed: [n=3] TRUE, TRUE, TRUE [05:57:23.124] | : queued futures: [n=3] TRUE, TRUE, TRUE [05:57:23.124] | signalConditionsASAP(MultisessionFuture, pos=3) ... done [05:57:23.124] | value(, ...) ... [05:57:23.124] | value(, ...) ... done [05:57:23.125] | value() for MultisessionFuture () ... [05:57:23.125] | : result() for ClusterFuture ... [05:57:23.125] | : . result already collected: FutureResult [05:57:23.125] | : result() for ClusterFuture ... done [05:57:23.126] | : result() for ClusterFuture ... [05:57:23.126] | : . result already collected: FutureResult [05:57:23.126] | : result() for ClusterFuture ... done [05:57:23.127] | : signalConditions() ... [05:57:23.127] | : . include = 'immediateCondition' [05:57:23.127] | : . exclude = [05:57:23.127] | : . resignal = FALSE [05:57:23.128] | : . Number of conditions: 0 [05:57:23.128] | : . int 0 [05:57:23.129] | : signalConditions() ... done [05:57:23.129] | : check for misuse ... [05:57:23.129] | : check for misuse ... done [05:57:23.130] | value() for MultisessionFuture () ... done [05:57:23.130] | value: [05:57:23.130] | signalConditionsASAP(MultisessionFuture, pos=3) ... [05:57:23.130] | : nx: 3 [05:57:23.131] | : relay: TRUE [05:57:23.131] | : stdout: TRUE [05:57:23.131] | : signal: TRUE [05:57:23.131] | : resignal: FALSE [05:57:23.132] | : force: TRUE [05:57:23.132] | : relayed: [n=3] TRUE, TRUE, TRUE [05:57:23.132] | : queued futures: [n=3] TRUE, TRUE, TRUE [05:57:23.132] | : until=3 [05:57:23.133] | : relayed: [n=3] TRUE, TRUE, TRUE [05:57:23.133] | : queued futures: [n=3] TRUE, TRUE, TRUE [05:57:23.133] | signalConditionsASAP(MultisessionFuture, pos=3) ... done [05:57:23.133] | resolve() for MultisessionFuture ... [05:57:23.135] | : length: 0 (resolved future 3) [05:57:23.135] | resolve() for MultisessionFuture ... done [05:57:23.135] | Relaying remaining futures ... [05:57:23.136] | : signalConditionsASAP(NULL, pos=0) ... [05:57:23.136] | : . nx: 3 [05:57:23.136] | : . relay: TRUE [05:57:23.136] | : . stdout: TRUE [05:57:23.137] | : . signal: TRUE [05:57:23.137] | : . resignal: FALSE [05:57:23.137] | : . force: TRUE [05:57:23.137] | : . relayed: [n=3] TRUE, TRUE, TRUE [05:57:23.138] | : . queued futures: [n=3] TRUE, TRUE, TRUE - flush all [05:57:23.138] | : . relayed: [n=3] TRUE, TRUE, TRUE [05:57:23.138] | : . queued futures: [n=3] TRUE, TRUE, TRUE [05:57:23.139] | : signalConditionsASAP(NULL, pos=0) ... done [05:57:23.139] | Relaying remaining futures ... done [05:57:23.139] value() for list ... done > print(js) [[1]] event category parent start at 1 create overhead 2025-06-05 05:57:22 0.00000000 secs 4 launch overhead 2025-06-05 05:57:22 0.04426312 secs 2 getWorker overhead launch 2025-06-05 05:57:22 0.05224800 secs 3 eraseWorker overhead launch 2025-06-05 05:57:22 0.25861311 secs 7 evaluate evaluation 2025-06-05 05:57:22 0.26912498 secs 5 receiveResult overhead gather 2025-06-05 05:57:22 0.60724115 secs 6 gather overhead 2025-06-05 05:57:22 0.63271999 secs duration future_label future_uuid 1 0.0433690548 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 4 0.2253739834 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 2 0.2043330669 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 3 0.0008909702 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 7 0.1027221680 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 5 0.0199840069 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 6 0.0007660389 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 session_uuid 1 9e39fe9a437f8a6d2e2455eb610c4bc9 4 9e39fe9a437f8a6d2e2455eb610c4bc9 2 9e39fe9a437f8a6d2e2455eb610c4bc9 3 9e39fe9a437f8a6d2e2455eb610c4bc9 7 f9ae746c0a766491fbbc6a0a28d4468e 5 9e39fe9a437f8a6d2e2455eb610c4bc9 6 9e39fe9a437f8a6d2e2455eb610c4bc9 [[2]] event category parent start at 1 create overhead 2025-06-05 05:57:22 0.00000000 secs 4 launch overhead 2025-06-05 05:57:22 0.03297591 secs 2 getWorker overhead launch 2025-06-05 05:57:22 0.03858399 secs 3 eraseWorker overhead launch 2025-06-05 05:57:22 0.24629283 secs 7 evaluate evaluation 2025-06-05 05:57:22 0.25631595 secs 5 receiveResult overhead gather 2025-06-05 05:57:23 0.48777199 secs 6 gather overhead 2025-06-05 05:57:23 0.50517297 secs duration future_label future_uuid 1 0.0323748589 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 4 0.2304620743 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 2 0.2053208351 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 3 0.0006110668 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 7 0.1246309280 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 5 0.0149009228 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 6 0.0005819798 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 session_uuid 1 9e39fe9a437f8a6d2e2455eb610c4bc9 4 9e39fe9a437f8a6d2e2455eb610c4bc9 2 9e39fe9a437f8a6d2e2455eb610c4bc9 3 9e39fe9a437f8a6d2e2455eb610c4bc9 7 99f93726084253d165997ab16dcef300 5 9e39fe9a437f8a6d2e2455eb610c4bc9 6 9e39fe9a437f8a6d2e2455eb610c4bc9 [[3]] event category parent start at 1 create overhead 2025-06-05 05:57:22 0.00000000 secs 4 launch overhead 2025-06-05 05:57:22 0.03166199 secs 2 getWorker overhead launch 2025-06-05 05:57:22 0.03902388 secs 3 eraseWorker overhead launch 2025-06-05 05:57:22 0.18738508 secs 7 evaluate evaluation 2025-06-05 05:57:23 0.19451404 secs 5 receiveResult overhead gather 2025-06-05 05:57:23 0.26866102 secs 6 gather overhead 2025-06-05 05:57:23 0.28833508 secs duration future_label future_uuid 1 0.0308959484 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 4 0.1652820110 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 2 0.1463651657 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 3 0.0006299019 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 7 0.0396809578 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 5 0.0163760185 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 6 0.0009307861 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 session_uuid 1 9e39fe9a437f8a6d2e2455eb610c4bc9 4 9e39fe9a437f8a6d2e2455eb610c4bc9 2 9e39fe9a437f8a6d2e2455eb610c4bc9 3 9e39fe9a437f8a6d2e2455eb610c4bc9 7 f9ae746c0a766491fbbc6a0a28d4468e 5 9e39fe9a437f8a6d2e2455eb610c4bc9 6 9e39fe9a437f8a6d2e2455eb610c4bc9 > stopifnot(is.list(js), all(vapply(js, FUN = is.data.frame, + FUN.VALUE = NA))) > plan(sequential) [05:57:23.151] plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:23.151] | plan(): plan_set(<1 strategies>, skip = FALSE, cleanup = NA, init = TRUE) ... [05:57:23.152] | : all.equal() for FutureStrategyList ... [05:57:23.152] | : . New stack: [05:57:23.152] | : . List of 1 [05:57:23.152] | : . $ :function (..., gc = FALSE, earlySignal = FALSE, envir = parent.frame()) [05:57:23.152] | : . ..- attr(*, "class")= chr [1:4] "sequential" "uniprocess" "future" "function" [05:57:23.152] | : . ..- attr(*, "init")= logi TRUE [05:57:23.152] | : . ..- attr(*, "factory")=function (..., maxSizeOfObjects = +Inf) [05:57:23.152] | : . .. ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.152] | : . ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.152] | : . ..- attr(*, "call")= language plan(sequential) [05:57:23.152] | : . - attr(*, "class")= chr [1:2] "FutureStrategyList" "list" [05:57:23.157] | : . Old stack: [05:57:23.157] | : . List of 1 [05:57:23.157] | : . $ :function (..., workers = 2, envir = parent.frame()) [05:57:23.157] | : . ..- attr(*, "class")= chr [1:6] "tweaked" "multisession" "cluster" "multiprocess" ... [05:57:23.157] | : . ..- attr(*, "init")= chr "done" [05:57:23.157] | : . ..- attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:23.157] | : . gc = FALSE, earlySignal = FALSE, ...) [05:57:23.157] | : . .. ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:23.157] | : . ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:23.157] | : . ..- attr(*, "untweakable")= chr "persistent" [05:57:23.157] | : . ..- attr(*, "tweaks")=List of 1 [05:57:23.157] | : . .. ..$ workers: num 2 [05:57:23.157] | : . ..- attr(*, "call")= language plan(multisession, workers = 2) [05:57:23.157] | : . ..- attr(*, "backend")=Classes 'MultisessionFutureBackend', 'ClusterFutureBackend', 'MultiprocessFutureBackend', 'FutureBackend', 'environment' [05:57:23.157] | : . .. ..- attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:23.157] | : . gc = FALSE, earlySignal = FALSE, ...) [05:57:23.157] | : . .. .. ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:23.157] | : . - attr(*, "class")= chr [1:2] "FutureStrategyList" "list" [05:57:23.165] | : . Not identical [05:57:23.166] | : . all.equal() for future ... [05:57:23.166] | : . ' List of 2 [05:57:23.166] | : . ' $ target :function (..., gc = FALSE, earlySignal = FALSE, envir = parent.frame()) [05:57:23.166] | : . ' ..- attr(*, "class")= chr [1:4] "sequential" "uniprocess" "future" "function" [05:57:23.166] | : . ' ..- attr(*, "init")= logi TRUE [05:57:23.166] | : . ' ..- attr(*, "factory")=function (..., maxSizeOfObjects = +Inf) [05:57:23.166] | : . ' .. ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.166] | : . ' ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.166] | : . ' ..- attr(*, "call")= language plan(sequential) [05:57:23.166] | : . ' $ current:function (..., workers = 2, envir = parent.frame()) [05:57:23.166] | : . ' ..- attr(*, "class")= chr [1:6] "tweaked" "multisession" "cluster" "multiprocess" ... [05:57:23.166] | : . ' ..- attr(*, "init")= chr "done" [05:57:23.166] | : . ' ..- attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:23.166] | : . ' gc = FALSE, earlySignal = FALSE, ...) [05:57:23.166] | : . ' .. ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:23.166] | : . ' ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:23.166] | : . ' ..- attr(*, "untweakable")= chr "persistent" [05:57:23.166] | : . ' ..- attr(*, "tweaks")=List of 1 [05:57:23.166] | : . ' .. ..$ workers: num 2 [05:57:23.166] | : . ' ..- attr(*, "call")= language plan(multisession, workers = 2) [05:57:23.166] | : . ' ..- attr(*, "backend")=Classes 'MultisessionFutureBackend', 'ClusterFutureBackend', 'MultiprocessFutureBackend', 'FutureBackend', 'environment' [05:57:23.166] | : . ' .. ..- attr(*, "factory")=function (workers = availableCores(), rscript_libs = .libPaths(), interrupts = TRUE, [05:57:23.166] | : . ' gc = FALSE, earlySignal = FALSE, ...) [05:57:23.166] | : . ' .. .. ..- attr(*, "tweakable")= chr [1:11] "workers" "rscript_libs" "interrupts" "gc" ... [05:57:23.177] | : . ' Formals differ [05:57:23.177] | : . all.equal() for future ... done [05:57:23.178] | : . Future strategies differ at level 1 [05:57:23.180] | : all.equal() for FutureStrategyList ... done [05:57:23.180] | : plan(): Setting new future backend stack: [05:57:23.180] | : List of future strategies: [05:57:23.180] | : 1. sequential: [05:57:23.180] | : - args: function (..., gc = FALSE, earlySignal = FALSE, envir = parent.frame(), workers = "") [05:57:23.180] | : - tweaked: FALSE [05:57:23.180] | : - call: plan(sequential) [05:57:23.181] | : List of 1 [05:57:23.181] | : $ :function (..., gc = FALSE, earlySignal = FALSE, envir = parent.frame()) [05:57:23.181] | : ..- attr(*, "class")= chr [1:4] "sequential" "uniprocess" "future" "function" [05:57:23.181] | : ..- attr(*, "init")= logi TRUE [05:57:23.181] | : ..- attr(*, "factory")=function (..., maxSizeOfObjects = +Inf) [05:57:23.181] | : .. ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.181] | : ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.181] | : ..- attr(*, "call")= language plan(sequential) [05:57:23.181] | : - attr(*, "class")= chr [1:2] "FutureStrategyList" "list" [05:57:23.186] | : plan(): plan_cleanup('tweaked', 'multisession', 'cluster', 'multiprocess', 'future', 'function', cleanup = NA) ... [05:57:23.186] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:23.186] | : . ' Getting current ("next") strategy: 'FutureStrategy', 'tweaked', 'multisession', 'cluster', 'multiprocess', 'future', 'function' [05:57:23.186] | : . plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:23.187] | : . stopWorkers() for MultisessionFutureBackend ... [05:57:23.187] | : . ' Interrupt active futures ... [05:57:23.188] | : . ' , Number of futures: 0 [05:57:23.188] | : . ' Interrupt active futures ... done [05:57:23.189] | : . ' Clear future registry ... [05:57:23.190] | : . ' Clear future registry ... done [05:57:23.190] | : . ' Stop cluster workers ... [05:57:23.190] | : . ' , Stopping existing cluster ... [05:57:23.190] | : . ' , ; Cluster to shut down: [05:57:23.190] | : . ' , ; Socket cluster with 2 nodes where 2 nodes are on host 'localhost' (R Under development (unstable) (2025-06-04 r88278 ucrt), platform x86_64-w64-mingw32) [05:57:23.200] | : . ' , ; Stopped cluster: 'c(TRUE, TRUE)' [05:57:23.279] | : . ' , Stopping existing cluster ... done [05:57:23.279] | : . ' Stop cluster workers ... done [05:57:23.280] | : . stopWorkers() for MultisessionFutureBackend ... done [05:57:23.280] | : . Legacy shutdown of cluster workers ... [05:57:23.280] | : . ' Stopping existing cluster ... [05:57:23.280] | : . ' , No pre-existing cluster. Skipping [05:57:23.281] | : . ' Stopping existing cluster ... done [05:57:23.281] | : . Legacy shutdown of cluster workers ... done [05:57:23.281] | : plan(): plan_cleanup('tweaked', 'multisession', 'cluster', 'multiprocess', 'future', 'function', cleanup = NA) ... done [05:57:23.282] | : plan(): plan_init() of 'sequential', 'uniprocess', 'future', 'function' ... [05:57:23.282] | : . function (..., gc = FALSE, earlySignal = FALSE, envir = parent.frame()) [05:57:23.282] | : . - attr(*, "class")= chr [1:4] "sequential" "uniprocess" "future" "function" [05:57:23.282] | : . - attr(*, "init")= logi TRUE [05:57:23.282] | : . - attr(*, "factory")=function (..., maxSizeOfObjects = +Inf) [05:57:23.282] | : . ..- attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.282] | : . - attr(*, "tweakable")= chr [1:5] "maxSizeOfObjects" "earlySignal" "gc" "interrupts" ... [05:57:23.282] | : . - attr(*, "call")= language plan(sequential) [05:57:23.286] | : . init: TRUE [05:57:23.286] | : . makeFutureBackend() ... [05:57:23.287] | : . ' Backend function: <'NULL'> [05:57:23.287] | : . ' Evaluator tweak arguments: [n=0] [05:57:23.287] | : . ' list() [05:57:23.288] | : . ' Evaluator formal arguments: [n=2] [05:57:23.288] | : . ' list() [05:57:23.288] | : . ' Backend factory arguments: [n=2] [05:57:23.289] | : . ' Dotted pair list of 2 [05:57:23.289] | : . ' $ gc : logi FALSE [05:57:23.289] | : . ' $ earlySignal: logi FALSE [05:57:23.291] | : . ' Backend: <'SequentialFutureBackend', 'FutureBackend', 'environment'> [05:57:23.291] | : . makeFutureBackend() ... done [05:57:23.291] | : plan(): plan_init() of 'sequential', 'uniprocess', 'future', 'function' ... done [05:57:23.291] | : plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... [05:57:23.292] | : plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done [05:57:23.292] | : plan(): nbrOfWorkers() = 1 [05:57:23.292] | plan(): plan_set(<1 strategies>, skip = FALSE, cleanup = NA, init = TRUE) ... done [05:57:23.293] plan(, .skip = FALSE, .cleanup = NA, .init = TRUE) ... done > message("*** capture_journals() ... done") *** capture_journals() ... done > message("*** summary() of FutureJournal ...") *** summary() of FutureJournal ... > js <- do.call(rbind, js) > print(js) event category parent start at 1 create overhead 2025-06-05 05:57:22 0.00000000 secs 4 launch overhead 2025-06-05 05:57:22 0.04426312 secs 2 getWorker overhead launch 2025-06-05 05:57:22 0.05224800 secs 3 eraseWorker overhead launch 2025-06-05 05:57:22 0.25861311 secs 7 evaluate evaluation 2025-06-05 05:57:22 0.26912498 secs 5 receiveResult overhead gather 2025-06-05 05:57:22 0.60724115 secs 6 gather overhead 2025-06-05 05:57:22 0.63271999 secs 11 create overhead 2025-06-05 05:57:22 0.00000000 secs 41 launch overhead 2025-06-05 05:57:22 0.03297591 secs 21 getWorker overhead launch 2025-06-05 05:57:22 0.03858399 secs 31 eraseWorker overhead launch 2025-06-05 05:57:22 0.24629283 secs 71 evaluate evaluation 2025-06-05 05:57:22 0.25631595 secs 51 receiveResult overhead gather 2025-06-05 05:57:23 0.48777199 secs 61 gather overhead 2025-06-05 05:57:23 0.50517297 secs 12 create overhead 2025-06-05 05:57:22 0.00000000 secs 42 launch overhead 2025-06-05 05:57:22 0.03166199 secs 22 getWorker overhead launch 2025-06-05 05:57:22 0.03902388 secs 32 eraseWorker overhead launch 2025-06-05 05:57:22 0.18738508 secs 72 evaluate evaluation 2025-06-05 05:57:23 0.19451404 secs 52 receiveResult overhead gather 2025-06-05 05:57:23 0.26866102 secs 62 gather overhead 2025-06-05 05:57:23 0.28833508 secs duration future_label future_uuid 1 0.0433690548 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 4 0.2253739834 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 2 0.2043330669 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 3 0.0008909702 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 7 0.1027221680 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 5 0.0199840069 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 6 0.0007660389 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-1 11 0.0323748589 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 41 0.2304620743 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 21 0.2053208351 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 31 0.0006110668 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 71 0.1246309280 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 51 0.0149009228 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 61 0.0005819798 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-2 12 0.0308959484 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 42 0.1652820110 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 22 0.1463651657 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 32 0.0006299019 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 72 0.0396809578 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 52 0.0163760185 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 62 0.0009307861 secs 9e39fe9a437f8a6d2e2455eb610c4bc9-3 session_uuid 1 9e39fe9a437f8a6d2e2455eb610c4bc9 4 9e39fe9a437f8a6d2e2455eb610c4bc9 2 9e39fe9a437f8a6d2e2455eb610c4bc9 3 9e39fe9a437f8a6d2e2455eb610c4bc9 7 f9ae746c0a766491fbbc6a0a28d4468e 5 9e39fe9a437f8a6d2e2455eb610c4bc9 6 9e39fe9a437f8a6d2e2455eb610c4bc9 11 9e39fe9a437f8a6d2e2455eb610c4bc9 41 9e39fe9a437f8a6d2e2455eb610c4bc9 21 9e39fe9a437f8a6d2e2455eb610c4bc9 31 9e39fe9a437f8a6d2e2455eb610c4bc9 71 99f93726084253d165997ab16dcef300 51 9e39fe9a437f8a6d2e2455eb610c4bc9 61 9e39fe9a437f8a6d2e2455eb610c4bc9 12 9e39fe9a437f8a6d2e2455eb610c4bc9 42 9e39fe9a437f8a6d2e2455eb610c4bc9 22 9e39fe9a437f8a6d2e2455eb610c4bc9 32 9e39fe9a437f8a6d2e2455eb610c4bc9 72 f9ae746c0a766491fbbc6a0a28d4468e 52 9e39fe9a437f8a6d2e2455eb610c4bc9 62 9e39fe9a437f8a6d2e2455eb610c4bc9 > stats <- summary(js) > print(stats) Number of futures: 3 summary evaluate evaluate_ratio overhead overhead_ratio 1 min 0.03968096 secs 0.1371782 0.1971087 secs 0.6814103 2 mean 0.08901135 secs 0.1869323 0.2433456 secs 0.5110488 3 median 0.10272217 secs 0.2031066 0.2634189 secs 0.5208430 4 max 0.12463093 secs 0.1967382 0.2695091 secs 0.4254381 5 total 0.26703405 secs 0.1869323 0.7300367 secs 0.5110488 duration walltime 1 0.2892659 secs 0.2892659 secs 2 0.4761690 secs 0.4761690 secs 3 0.5057549 secs 0.5057549 secs 4 0.6334860 secs 0.6334860 secs 5 1.4285069 secs 1.4285069 secs > message("*** summary() of FutureJournal ... done") *** summary() of FutureJournal ... done Sourcing 6 epilogue scripts ... 01/06 epilogue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_epilogue/001.undo-future.R' 02/06 epilogue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_epilogue/002.undo-state.R' Failed to undo environment variables: - Expected environment variables: [n=213] '!ExitCode', 'ALLUSERSPROFILE', 'APPDATA', 'BIBINPUTS', 'BINDIR', 'BSTINPUTS', 'COMMONPROGRAMFILES', 'COMPUTERNAME', 'COMSPEC', 'CURL_CA_BUNDLE', 'CYGWIN', 'CommonProgramFiles(x86)', 'CommonProgramW6432', 'DriverData', 'HOME', 'HOMEDRIVE', 'HOMEPATH', 'JAGS_ROOT', 'JAVA_HOME', 'LANGUAGE', 'LC_COLLATE', 'LC_MONETARY', 'LC_TIME', 'LOCALAPPDATA', 'LOGONSERVER', 'LS_HOME', 'LS_LICENSE_PATH', 'MAKE', 'MAKEFLAGS', 'MAKELEVEL', 'MFLAGS', 'MSMPI_BENCHMARKS', 'MSMPI_BIN', 'MSYS2_ENV_CONV_EXCL', 'NUMBER_OF_PROCESSORS', 'OCL', 'OMP_THREAD_LIMIT', 'OS', 'PATH', 'PATHEXT', 'PROCESSOR_ARCHITECTURE', 'PROCESSOR_IDENTIFIER', 'PROCESSOR_LEVEL', 'PROCESSOR_REVISION', 'PROGRAMFILES', 'PROMPT', 'PSModulePath', 'PUBLIC', 'PWD', 'ProgramData', 'ProgramFiles(x86)', 'ProgramW6432', 'RTOOLS44_HOME', 'RTOOLS45_HOME', 'R_ARCH', 'R_BROWSER', 'R_BZIPCMD', 'R_CMD', 'R_COMPILED_BY', 'R_CRAN_WEB', 'R_CUSTOM_TOOLS_PATH', 'R_CUSTOM_TOOLS_SOFT', 'R_DOC_DIR', 'R_ENVIRON_USER', 'R_GSCMD', 'R_GZIPCMD', 'R_HOME', 'R_INCLUDE_DIR', 'R_INSTALL_TAR', 'R_LIBS', 'R_LIBS_SITE', 'R_LIBS_USER', 'R_MAX_NUM_DLLS', 'R_OSTYPE', 'R_PAPERSIZE', 'R_PAPERSIZE_USER', 'R_PARALLELLY_MAKENODEPSOCK_AUTOKILL', 'R_PARALLELLY_MAKENODEPSOCK_CONNECTTIMEOUT', 'R_PARALLELLY_MAKENODEPSOCK_RSCRIPT_LABEL', 'R_PARALLELLY_MAKENODEPSOCK_SESSIONINFO_PKGS', 'R_PARALLELLY_MAKENODEPSOCK_TIMEOUT', 'R_PARALLELLY_RANDOM_PORTS', 'R_PARALLEL_PORT', 'R_RD4PDF', 'R_RTOOLS45_PATH', 'R_SCRIPT_LEGACY', 'R_SHARE_DIR', 'R_TESTME_NAME', 'R_TESTME_PACKAGE', 'R_TESTME_PATH', 'R_TESTS', 'R_UNZIPCMD', 'R_USER', 'R_VERSION', 'R_ZIPCMD', 'SED', 'SHLVL', 'SYSTEMDRIVE', 'SYSTEMROOT', 'TAR', 'TAR_OPTIONS', 'TEMP', 'TERM', 'TEXINPUTS', 'TMP', 'TMPDIR', 'USERDOMAIN', 'USERDOMAIN_ROAMINGPROFILE', 'USERNAME', 'USERPROFILE', 'WINDIR', '_', '_R_CHECK_AUTOCONF_', '_R_CHECK_BOGUS_RETURN_', '_R_CHECK_BROWSER_NONINTERACTIVE_', '_R_CHECK_BUILD_VIGNETTES_SEPARATELY_', '_R_CHECK_CODETOOLS_PROFILE_', '_R_CHECK_CODE_ASSIGN_TO_GLOBALENV_', '_R_CHECK_CODE_ATTACH_', '_R_CHECK_CODE_CLASS_IS_STRING_', '_R_CHECK_CODE_DATA_INTO_GLOBALENV_', '_R_CHECK_CODE_USAGE_VIA_NAMESPACES_', '_R_CHECK_CODE_USAGE_WITHOUT_LOADING_', '_R_CHECK_CODE_USAGE_WITH_ONLY_BASE_ATTACHED_', '_R_CHECK_CODOC_VARIABLES_IN_USAGES_', '_R_CHECK_COMPACT_DATA2_', '_R_CHECK_COMPILATION_FLAGS_', '_R_CHECK_CONNECTIONS_LEFT_OPEN_', '_R_CHECK_CRAN_INCOMING_', '_R_CHECK_CRAN_INCOMING_ASPELL_RECHECK_MAYBE_', '_R_CHECK_CRAN_INCOMING_ASPELL_RECHECK_START_', '_R_CHECK_CRAN_INCOMING_CHECK_FILE_URIS_', '_R_CHECK_CRAN_INCOMING_CHECK_URLS_IN_PARALLEL_', '_R_CHECK_CRAN_INCOMING_NOTE_GNU_MAKE_', '_R_CHECK_CRAN_INCOMING_REMOTE_', '_R_CHECK_CRAN_INCOMING_USE_ASPELL_', '_R_CHECK_DATALIST_', '_R_CHECK_DEPRECATED_DEFUNCT_', '_R_CHECK_DOC_SIZES2_', '_R_CHECK_DOT_FIRSTLIB_', '_R_CHECK_DOT_INTERNAL_', '_R_CHECK_EXAMPLE_TIMING_THRESHOLD_', '_R_CHECK_EXECUTABLES_', '_R_CHECK_EXECUTABLES_EXCLUSIONS_', '_R_CHECK_FF_CALLS_', '_R_CHECK_FF_DUP_', '_R_CHECK_FORCE_SUGGESTS_', '_R_CHECK_FUTURE_FILE_TIMESTAMPS_', '_R_CHECK_FUTURE_FILE_TIMESTAMPS_LEEWAY_', '_R_CHECK_HAVE_MYSQL_', '_R_CHECK_HAVE_ODBC_', '_R_CHECK_HAVE_PERL_', '_R_CHECK_HAVE_POSTGRES_', '_R_CHECK_INSTALL_DEPENDS_', '_R_CHECK_INTERNALS2_', '_R_CHECK_LENGTH_1_CONDITION_', '_R_CHECK_LICENSE_', '_R_CHECK_LIMIT_CORES_', '_R_CHECK_LOG_USE_INFO_', '_R_CHECK_MATRIX_DATA_', '_R_CHECK_MBCS_CONVERSION_FAILURE_', '_R_CHECK_NATIVE_ROUTINE_REGISTRATION_', '_R_CHECK_NEWS_IN_PLAIN_TEXT_', '_R_CHECK_NO_RECOMMENDED_', '_R_CHECK_NO_STOP_ON_TEST_ERROR_', '_R_CHECK_ORPHANED_', '_R_CHECK_OVERWRITE_REGISTERED_S3_METHODS_', '_R_CHECK_PACKAGES_USED_IGNORE_UNUSED_IMPORTS_', '_R_CHECK_PACKAGES_USED_IN_TESTS_USE_SUBDIRS_', '_R_CHECK_PACKAGE_DATASETS_SUPPRESS_NOTES_', '_R_CHECK_PACKAGE_NAME_', '_R_CHECK_PKG_SIZES_', '_R_CHECK_PKG_SIZES_THRESHOLD_', '_R_CHECK_PRAGMAS_', '_R_CHECK_RD_EXAMPLES_T_AND_F_', '_R_CHECK_RD_LINE_WIDTHS_', '_R_CHECK_RD_MATH_RENDERING_', '_R_CHECK_RD_NOTE_LOST_BRACES_', '_R_CHECK_RD_VALIDATE_RD2HTML_', '_R_CHECK_REPLACING_IMPORTS_', '_R_CHECK_R_DEPENDS_', '_R_CHECK_S3_METHODS_SHOW_POSSIBLE_ISSUES_', '_R_CHECK_SCREEN_DEVICE_', '_R_CHECK_SERIALIZATION_', '_R_CHECK_SHLIB_OPENMP_FLAGS_', '_R_CHECK_SRC_MINUS_W_IMPLICIT_', '_R_CHECK_SUBDIRS_NOCASE_', '_R_CHECK_SUGGESTS_ONLY_', '_R_CHECK_SYSTEM_CLOCK_', '_R_CHECK_TESTS_NLINES_', '_R_CHECK_TEST_TIMING_', '_R_CHECK_TIMINGS_', '_R_CHECK_TOPLEVEL_FILES_', '_R_CHECK_UNDOC_USE_ALL_NAMES_', '_R_CHECK_UNSAFE_CALLS_', '_R_CHECK_URLS_SHOW_301_STATUS_', '_R_CHECK_VC_DIRS_', '_R_CHECK_VIGNETTES_NLINES_', '_R_CHECK_VIGNETTES_SKIP_RUN_MAYBE_', '_R_CHECK_VIGNETTE_TIMING_', '_R_CHECK_VIGNETTE_TITLES_', '_R_CHECK_WINDOWS_DEVICE_', '_R_CHECK_XREFS_NOTE_MISSING_PACKAGE_ANCHORS_', '_R_CHECK_XREFS_USE_ALIASES_FROM_CRAN_', '_R_CLASS_MATRIX_ARRAY_', '_R_DEPRECATED_IS_R_', '_R_S3_METHOD_LOOKUP_BASEENV_AFTER_GLOBALENV_', '_R_SHLIB_BUILD_OBJECTS_SYMBOL_TABLES_', '_R_USE_STRICT_R_HEADERS_', '__R_CHECK_DOC_FILES_NOTE_IF_ALL_SPECIAL__', 'maj.version', 'nextArg--timingsnextArg--install', 'tempdirname' - Environment variables still there: [n=0] - Environment variables missing: [n=1] 'MAKEFLAGS' Differences environment variable by environment variable: 03/06 epilogue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_epilogue/090.gc.R' 04/06 epilogue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_epilogue/099.session_info.R' 05/06 epilogue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_epilogue/995.detritus-connections.R' 06/06 epilogue script 'D:/RCompile/CRANincoming/R-devel/lib/future/testme/_epilogue/999.detritus-files.R' Skipping, because path appears not to be an 'R CMD check' folder: 'D:/temp/2025_06_05_05_55_16_20588' Sourcing 6 epilogue scripts ... done Test time: user.self=1s, sys.self=0.04s, elapsed=2s, user.child=NAs, sys.child=NAs Test 'capture_journals' ... success > > proc.time() user system elapsed 1.20 0.21 2.42