profiling mirai 2.0.0

[wlandau]

Just thought I'd share a profiling study and data for mirai 2.0.0. I stress tested mirai on my M2 MacBook using a workflow with 20 workers and 100000 tasks.

Performance overall is fantastic. From the timestamps, it looks like things slow down a bit as the number of submitted tasks increases.

proffer::pprof({ library(mirai) daemons(url = "tcp://127.0.0.1:57000") replicate(20L, launch_local(url = "tcp://127.0.0.1:57000")) index <- 1L tasks <- new.env(parent = emptyenv(), hash = TRUE) start <- as.numeric(proc.time()["elapsed"]) while (index < 1e5L) { tasks[[basename(tempfile())]] <- mirai(Sys.sleep(0.005)) if (!(index %% 1e3L)) { counters <- status()$mirai print( paste0( "time: ", format(Sys.time(), "%M:%OS3"), " | submitted: ", index, " | awaiting: ", counters["awaiting"], " | executing: ", counters["executing"], " | completed: ", counters["completed"] ) ) } index <- index + 1L } print(as.numeric(proc.time()["elapsed"]) - start) daemons(n = 0L) }) # [1] "time: 47:29.652 | submitted: 1000 | awaiting: 787 | executing: 20 | completed: 193" # [1] "time: 47:29.693 | submitted: 2000 | awaiting: 1666 | executing: 20 | completed: 314" # [1] "time: 47:29.735 | submitted: 3000 | awaiting: 2546 | executing: 20 | completed: 434" # [1] "time: 47:29.781 | submitted: 4000 | awaiting: 3407 | executing: 20 | completed: 573" # [1] "time: 47:29.828 | submitted: 5000 | awaiting: 4267 | executing: 20 | completed: 713" # [1] "time: 47:29.878 | submitted: 6000 | awaiting: 5115 | executing: 20 | completed: 865" # [1] "time: 47:29.931 | submitted: 7000 | awaiting: 5967 | executing: 20 | completed: 1013" # [1] "time: 47:29.993 | submitted: 8000 | awaiting: 6779 | executing: 20 | completed: 1201" # [1] "time: 47:30.055 | submitted: 9000 | awaiting: 7605 | executing: 20 | completed: 1375" # [1] "time: 47:30.135 | submitted: 10000 | awaiting: 8366 | executing: 20 | completed: 1614" # [1] "time: 47:30.217 | submitted: 11000 | awaiting: 9127 | executing: 20 | completed: 1853" # [1] "time: 47:30.300 | submitted: 12000 | awaiting: 9887 | executing: 20 | completed: 2093" # [1] "time: 47:30.392 | submitted: 13000 | awaiting: 10626 | executing: 20 | completed: 2354" # [1] "time: 47:30.510 | submitted: 14000 | awaiting: 11290 | executing: 20 | completed: 2690" # [1] "time: 47:30.631 | submitted: 15000 | awaiting: 11953 | executing: 20 | completed: 3027" # [1] "time: 47:30.773 | submitted: 16000 | awaiting: 12561 | executing: 20 | completed: 3419" # [1] "time: 47:30.925 | submitted: 17000 | awaiting: 13145 | executing: 20 | completed: 3835" # [1] "time: 47:31.118 | submitted: 18000 | awaiting: 13649 | executing: 20 | completed: 4331" # [1] "time: 47:31.268 | submitted: 19000 | awaiting: 14262 | executing: 20 | completed: 4718" # [1] "time: 47:31.453 | submitted: 20000 | awaiting: 14777 | executing: 20 | completed: 5203" # [1] "time: 47:31.647 | submitted: 21000 | awaiting: 15293 | executing: 20 | completed: 5687" # [1] "time: 47:31.856 | submitted: 22000 | awaiting: 15765 | executing: 20 | completed: 6215" # [1] "time: 47:32.077 | submitted: 23000 | awaiting: 16211 | executing: 20 | completed: 6769" # [1] "time: 47:32.294 | submitted: 24000 | awaiting: 16680 | executing: 20 | completed: 7300" # [1] "time: 47:32.530 | submitted: 25000 | awaiting: 17102 | executing: 20 | completed: 7878" # [1] "time: 47:32.755 | submitted: 26000 | awaiting: 17585 | executing: 20 | completed: 8395" # [1] "time: 47:32.957 | submitted: 27000 | awaiting: 18157 | executing: 20 | completed: 8823" # [1] "time: 47:33.171 | submitted: 28000 | awaiting: 18676 | executing: 20 | completed: 9304" # [1] "time: 47:33.380 | submitted: 29000 | awaiting: 19251 | executing: 20 | completed: 9729" # [1] "time: 47:33.749 | submitted: 30000 | awaiting: 19473 | executing: 20 | completed: 10507" # [1] "time: 47:34.160 | submitted: 31000 | awaiting: 19559 | executing: 20 | completed: 11421" # [1] "time: 47:34.584 | submitted: 32000 | awaiting: 19613 | executing: 20 | completed: 12367" # [1] "time: 47:35.014 | submitted: 33000 | awaiting: 19690 | executing: 20 | completed: 13290" # [1] "time: 47:35.431 | submitted: 34000 | awaiting: 19762 | executing: 20 | completed: 14218" # [1] "time: 47:35.857 | submitted: 35000 | awaiting: 19822 | executing: 20 | completed: 15158" # [1] "time: 47:36.286 | submitted: 36000 | awaiting: 19880 | executing: 20 | completed: 16100" # [1] "time: 47:36.680 | submitted: 37000 | awaiting: 20031 | executing: 20 | completed: 16949" # [1] "time: 47:37.025 | submitted: 38000 | awaiting: 20280 | executing: 20 | completed: 17700" # [1] "time: 47:37.384 | submitted: 39000 | awaiting: 20505 | executing: 20 | completed: 18475" # [1] "time: 47:37.737 | submitted: 40000 | awaiting: 20764 | executing: 20 | completed: 19216" # [1] "time: 47:38.108 | submitted: 41000 | awaiting: 21037 | executing: 20 | completed: 19943" # [1] "time: 47:38.438 | submitted: 42000 | awaiting: 21379 | executing: 20 | completed: 20601" # [1] "time: 47:38.753 | submitted: 43000 | awaiting: 21748 | executing: 20 | completed: 21232" # [1] "time: 47:39.088 | submitted: 44000 | awaiting: 22084 | executing: 20 | completed: 21896" # [1] "time: 47:39.448 | submitted: 45000 | awaiting: 22384 | executing: 20 | completed: 22596" # [1] "time: 47:39.822 | submitted: 46000 | awaiting: 22666 | executing: 20 | completed: 23314" # [1] "time: 47:40.136 | submitted: 47000 | awaiting: 23087 | executing: 20 | completed: 23893" # [1] "time: 47:40.446 | submitted: 48000 | awaiting: 23510 | executing: 20 | completed: 24470" # [1] "time: 47:40.764 | submitted: 49000 | awaiting: 23939 | executing: 20 | completed: 25041" # [1] "time: 47:41.107 | submitted: 50000 | awaiting: 24313 | executing: 20 | completed: 25667" # [1] "time: 47:41.441 | submitted: 51000 | awaiting: 24726 | executing: 20 | completed: 26254" # [1] "time: 47:41.960 | submitted: 52000 | awaiting: 24650 | executing: 20 | completed: 27330" # [1] "time: 47:42.262 | submitted: 53000 | awaiting: 25142 | executing: 20 | completed: 27838" # [1] "time: 47:42.589 | submitted: 54000 | awaiting: 25580 | executing: 20 | completed: 28400" # [1] "time: 47:42.908 | submitted: 55000 | awaiting: 26061 | executing: 20 | completed: 28919" # [1] "time: 47:43.203 | submitted: 56000 | awaiting: 26590 | executing: 20 | completed: 29390" # [1] "time: 47:43.507 | submitted: 57000 | awaiting: 27119 | executing: 20 | completed: 29861" # [1] "time: 47:43.805 | submitted: 58000 | awaiting: 27667 | executing: 20 | completed: 30313" # [1] "time: 47:44.118 | submitted: 59000 | awaiting: 28178 | executing: 20 | completed: 30802" # [1] "time: 47:44.440 | submitted: 60000 | awaiting: 28701 | executing: 20 | completed: 31279" # [1] "time: 47:44.947 | submitted: 61000 | awaiting: 28963 | executing: 20 | completed: 32017" # [1] "time: 47:45.525 | submitted: 62000 | awaiting: 29044 | executing: 20 | completed: 32936" # [1] "time: 47:46.083 | submitted: 63000 | awaiting: 29160 | executing: 20 | completed: 33820" # [1] "time: 47:46.543 | submitted: 64000 | awaiting: 29443 | executing: 20 | completed: 34537" # [1] "time: 47:47.012 | submitted: 65000 | awaiting: 29716 | executing: 20 | completed: 35264" # [1] "time: 47:47.505 | submitted: 66000 | awaiting: 29985 | executing: 20 | completed: 35995" # [1] "time: 47:47.887 | submitted: 67000 | awaiting: 30438 | executing: 20 | completed: 36542" # [1] "time: 47:48.311 | submitted: 68000 | awaiting: 30820 | executing: 20 | completed: 37160" # [1] "time: 47:48.763 | submitted: 69000 | awaiting: 31176 | executing: 20 | completed: 37804" # [1] "time: 47:49.190 | submitted: 70000 | awaiting: 31593 | executing: 20 | completed: 38387" # [1] "time: 47:49.566 | submitted: 71000 | awaiting: 32087 | executing: 20 | completed: 38893" # [1] "time: 47:49.935 | submitted: 72000 | awaiting: 32588 | executing: 20 | completed: 39392" # [1] "time: 47:50.314 | submitted: 73000 | awaiting: 33074 | executing: 20 | completed: 39906" # [1] "time: 47:50.692 | submitted: 74000 | awaiting: 33588 | executing: 20 | completed: 40392" # [1] "time: 47:51.059 | submitted: 75000 | awaiting: 34137 | executing: 20 | completed: 40843" # [1] "time: 47:51.412 | submitted: 76000 | awaiting: 34687 | executing: 20 | completed: 41293" # [1] "time: 47:51.781 | submitted: 77000 | awaiting: 35230 | executing: 20 | completed: 41750" # [1] "time: 47:52.158 | submitted: 78000 | awaiting: 35780 | executing: 20 | completed: 42200" # [1] "time: 47:52.494 | submitted: 79000 | awaiting: 36389 | executing: 20 | completed: 42591" # [1] "time: 47:52.847 | submitted: 80000 | awaiting: 36973 | executing: 20 | completed: 43007" # [1] "time: 47:53.221 | submitted: 81000 | awaiting: 37560 | executing: 20 | completed: 43420" # [1] "time: 47:53.805 | submitted: 82000 | awaiting: 37986 | executing: 20 | completed: 43994" # [1] "time: 47:54.565 | submitted: 83000 | awaiting: 38067 | executing: 20 | completed: 44913" # [1] "time: 47:55.259 | submitted: 84000 | awaiting: 38235 | executing: 20 | completed: 45745" # [1] "time: 47:55.868 | submitted: 85000 | awaiting: 38498 | executing: 20 | completed: 46482" # [1] "time: 47:56.495 | submitted: 86000 | awaiting: 38758 | executing: 20 | completed: 47222" # [1] "time: 47:57.026 | submitted: 87000 | awaiting: 39151 | executing: 20 | completed: 47829" # [1] "time: 47:57.576 | submitted: 88000 | awaiting: 39541 | executing: 20 | completed: 48439" # [1] "time: 47:58.082 | submitted: 89000 | awaiting: 39970 | executing: 20 | completed: 49010" # [1] "time: 47:58.563 | submitted: 90000 | awaiting: 40467 | executing: 20 | completed: 49513" # [1] "time: 47:59.031 | submitted: 91000 | awaiting: 40960 | executing: 20 | completed: 50020" # [1] "time: 47:59.470 | submitted: 92000 | awaiting: 41496 | executing: 20 | completed: 50484" # [1] "time: 47:59.877 | submitted: 93000 | awaiting: 42070 | executing: 20 | completed: 50910" # [1] "time: 48:00.524 | submitted: 94000 | awaiting: 42215 | executing: 20 | completed: 51765" # [1] "time: 48:00.892 | submitted: 95000 | awaiting: 42790 | executing: 20 | completed: 52190" # [1] "time: 48:01.262 | submitted: 96000 | awaiting: 43372 | executing: 20 | completed: 52608" # [1] "time: 48:01.655 | submitted: 97000 | awaiting: 43933 | executing: 20 | completed: 53047" # [1] "time: 48:02.240 | submitted: 98000 | awaiting: 44306 | executing: 20 | completed: 53674" # [1] "time: 48:03.063 | submitted: 99000 | awaiting: 44348 | executing: 20 | completed: 54632" # [1] 33.889 # • url: <http://localhost:65157/ui/flamegraph> # • host: localhost # • port: 65157

And here is the pprof flame graph showing where the code spends most of its time:

[wlandau]

With https://github.com/wlandau/crew/tree/193, I've hit cases where status() is much slower and status()$mirai returns NA for all the counters. crew can handle this, but it does make me look forward to the threaded dispatcher (presumably this information will be available instantaneously without needing explicit queries).

[shikokuchuo]

A reprex will help greatly. Otherwise I can't know what's really happening.

I've never seen even one timeout, so I have no idea what it looks like if you get one timeout and then have one succeed. I don't think it's a throughput issue as I run performance tests with interspersed status() calls as part of CI, so is it large data?

[wlandau]

It's small data, and the frequency of dispatcher queries depends on connection/disconnection events and crew's new deterministic binary exponential backoff algorithm.

I'm okay with timeouts, I just need to make sure connect/disconnect events don't get lost in the event of a timeout (i.e. all events that would have been reported before are successfully reported on the next non-timeout).

I'm having trouble creating a reprex with just mirai, but here's one using wlandau/crew@ab8aeaa (with special instrumentation in crew:::mirai_status()). From the output, you'll notice a timeout between 55000 and 60000 pushed tasks and a total of about 6 seconds trying to query the dispatcher in that instance.

controller <- crew::crew_controller_local(workers = 25L) controller$start() n <- 1e5 for (index in seq_len(n)) { if (!(index %% 5e3)) { message(paste("push", index, "of", n)) } controller$push(TRUE) } controller$terminate()

10:26:32.95 BEGIN dispatcher query loop 10:26:32.95 querying dispatcher query succeeded 10:26:32.95 END dispatcher query loop 10:26:32.98 BEGIN dispatcher query loop 10:26:32.98 querying dispatcher query succeeded 10:26:32.98 END dispatcher query loop 10:26:33.01 BEGIN dispatcher query loop 10:26:33.01 querying dispatcher query succeeded 10:26:33.01 END dispatcher query loop 10:26:33.01 BEGIN dispatcher query loop 10:26:33.01 querying dispatcher query succeeded 10:26:33.01 END dispatcher query loop 10:26:33.02 BEGIN dispatcher query loop 10:26:33.02 querying dispatcher query succeeded 10:26:33.02 END dispatcher query loop 10:26:33.03 BEGIN dispatcher query loop 10:26:33.03 querying dispatcher query succeeded 10:26:33.03 END dispatcher query loop 10:26:33.04 BEGIN dispatcher query loop 10:26:33.04 querying dispatcher query succeeded 10:26:33.04 END dispatcher query loop 10:26:33.05 BEGIN dispatcher query loop 10:26:33.06 querying dispatcher query succeeded 10:26:33.06 END dispatcher query loop 10:26:33.07 BEGIN dispatcher query loop 10:26:33.07 querying dispatcher query succeeded 10:26:33.07 END dispatcher query loop 10:26:33.08 BEGIN dispatcher query loop 10:26:33.08 querying dispatcher query succeeded 10:26:33.08 END dispatcher query loop 10:26:33.10 BEGIN dispatcher query loop 10:26:33.10 querying dispatcher query succeeded 10:26:33.10 END dispatcher query loop 10:26:33.11 BEGIN dispatcher query loop 10:26:33.11 querying dispatcher query succeeded 10:26:33.12 END dispatcher query loop 10:26:33.13 BEGIN dispatcher query loop 10:26:33.13 querying dispatcher query succeeded 10:26:33.13 END dispatcher query loop 10:26:33.14 BEGIN dispatcher query loop 10:26:33.14 querying dispatcher query succeeded 10:26:33.14 END dispatcher query loop 10:26:33.15 BEGIN dispatcher query loop 10:26:33.15 querying dispatcher query succeeded 10:26:33.15 END dispatcher query loop 10:26:33.17 BEGIN dispatcher query loop 10:26:33.17 querying dispatcher query succeeded 10:26:33.17 END dispatcher query loop 10:26:33.18 BEGIN dispatcher query loop 10:26:33.18 querying dispatcher query succeeded 10:26:33.18 END dispatcher query loop 10:26:33.21 BEGIN dispatcher query loop 10:26:33.21 querying dispatcher query succeeded 10:26:33.21 END dispatcher query loop 10:26:33.23 BEGIN dispatcher query loop 10:26:33.23 querying dispatcher query succeeded 10:26:33.23 END dispatcher query loop 10:26:33.24 BEGIN dispatcher query loop 10:26:33.24 querying dispatcher query succeeded 10:26:33.25 END dispatcher query loop 10:26:33.26 BEGIN dispatcher query loop 10:26:33.26 querying dispatcher query succeeded 10:26:33.26 END dispatcher query loop 10:26:33.28 BEGIN dispatcher query loop 10:26:33.28 querying dispatcher query succeeded 10:26:33.28 END dispatcher query loop 10:26:33.29 BEGIN dispatcher query loop 10:26:33.29 querying dispatcher query succeeded 10:26:33.29 END dispatcher query loop 10:26:33.30 BEGIN dispatcher query loop 10:26:33.30 querying dispatcher query succeeded 10:26:33.31 END dispatcher query loop 10:26:33.32 BEGIN dispatcher query loop 10:26:33.32 querying dispatcher query succeeded 10:26:33.34 END dispatcher query loop 10:26:33.48 BEGIN dispatcher query loop 10:26:33.48 querying dispatcher query succeeded 10:26:33.52 END dispatcher query loop 10:26:33.52 BEGIN dispatcher query loop 10:26:33.52 querying dispatcher query succeeded 10:26:33.52 END dispatcher query loop 10:26:33.53 BEGIN dispatcher query loop 10:26:33.53 querying dispatcher query succeeded 10:26:33.53 END dispatcher query loop 10:26:33.54 BEGIN dispatcher query loop 10:26:33.54 querying dispatcher query succeeded 10:26:33.54 END dispatcher query loop 10:26:33.55 BEGIN dispatcher query loop 10:26:33.55 querying dispatcher query succeeded 10:26:33.55 END dispatcher query loop 10:26:33.58 BEGIN dispatcher query loop 10:26:33.58 querying dispatcher query succeeded 10:26:33.58 END dispatcher query loop 10:26:33.65 BEGIN dispatcher query loop 10:26:33.65 querying dispatcher query succeeded 10:26:33.66 END dispatcher query loop 10:26:33.85 BEGIN dispatcher query loop 10:26:33.85 querying dispatcher query succeeded 10:26:33.85 END dispatcher query loop 10:26:34.14 BEGIN dispatcher query loop 10:26:34.14 querying dispatcher query succeeded 10:26:34.14 END dispatcher query loop 10:26:34.67 BEGIN dispatcher query loop 10:26:34.67 querying dispatcher query succeeded 10:26:34.72 END dispatcher query loop 10:26:34.72 BEGIN dispatcher query loop 10:26:34.72 querying dispatcher query succeeded 10:26:34.72 END dispatcher query loop 10:26:34.72 BEGIN dispatcher query loop 10:26:34.72 querying dispatcher query succeeded 10:26:34.72 END dispatcher query loop 10:26:34.73 BEGIN dispatcher query loop 10:26:34.73 querying dispatcher query succeeded 10:26:34.73 END dispatcher query loop 10:26:34.73 BEGIN dispatcher query loop 10:26:34.73 querying dispatcher query succeeded 10:26:34.74 END dispatcher query loop push 5000 of 1e+05 10:26:34.75 BEGIN dispatcher query loop 10:26:34.75 querying dispatcher query succeeded 10:26:34.79 END dispatcher query loop 10:26:34.79 BEGIN dispatcher query loop 10:26:34.79 querying dispatcher query succeeded 10:26:34.79 END dispatcher query loop 10:26:34.86 BEGIN dispatcher query loop 10:26:34.86 querying dispatcher query succeeded 10:26:35.07 END dispatcher query loop 10:26:35.07 BEGIN dispatcher query loop 10:26:35.07 querying dispatcher query succeeded 10:26:35.07 END dispatcher query loop push 10000 of 1e+05 10:26:35.33 BEGIN dispatcher query loop 10:26:35.33 querying dispatcher query succeeded 10:26:36.04 END dispatcher query loop 10:26:36.04 BEGIN dispatcher query loop 10:26:36.04 querying dispatcher query succeeded 10:26:36.04 END dispatcher query loop push 15000 of 1e+05 push 20000 of 1e+05 push 25000 of 1e+05 push 30000 of 1e+05 10:26:37.06 BEGIN dispatcher query loop 10:26:37.06 querying dispatcher query succeeded 10:26:39.15 END dispatcher query loop 10:26:39.15 BEGIN dispatcher query loop 10:26:39.15 querying dispatcher query succeeded 10:26:39.15 END dispatcher query loop push 35000 of 1e+05 push 40000 of 1e+05 push 45000 of 1e+05 push 50000 of 1e+05 push 55000 of 1e+05 10:26:40.15 BEGIN dispatcher query loop 10:26:40.15 querying dispatcher query failed with status 5 10:26:46.16 querying dispatcher query succeeded 10:26:46.71 END dispatcher query loop 10:26:46.71 BEGIN dispatcher query loop 10:26:46.71 querying dispatcher query succeeded 10:26:46.71 END dispatcher query loop push 60000 of 1e+05 push 65000 of 1e+05 push 70000 of 1e+05 push 75000 of 1e+05 10:26:47.83 BEGIN dispatcher query loop 10:26:47.83 querying dispatcher query succeeded 10:26:52.31 END dispatcher query loop 10:26:52.31 BEGIN dispatcher query loop 10:26:52.31 querying dispatcher query succeeded 10:26:52.31 END dispatcher query loop push 80000 of 1e+05 push 85000 of 1e+05 push 90000 of 1e+05 push 95000 of 1e+05 push 100000 of 1e+05

> sessionInfo() R version 4.4.0 (2024-04-24) Platform: aarch64-apple-darwin20 Running under: macOS 15.3 Matrix products: default BLAS: /System/Library/Frameworks/Accelerate.framework/Versions/A/Frameworks/vecLib.framework/Versions/A/libBLAS.dylib LAPACK: /Library/Frameworks/R.framework/Versions/4.4-arm64/Resources/lib/libRlapack.dylib; LAPACK version 3.12.0 locale: [1] en_US.UTF-8/en_US.UTF-8/en_US.UTF-8/C/en_US.UTF-8/en_US.UTF-8 time zone: America/Indiana/Indianapolis tzcode source: internal attached base packages: [1] stats graphics grDevices utils datasets methods base other attached packages: [1] crew_1.0.0 loaded via a namespace (and not attached): [1] mirai_2.0.1.9005 later_1.3.2 R6_2.5.1 tidyselect_1.2.1 [5] magrittr_2.0.3 glue_1.8.0 nanonext_1.4.0.9004 tibble_3.2.1 [9] pkgconfig_2.0.3 lifecycle_1.0.4 ps_1.8.1 promises_1.3.0 [13] cli_3.6.3 processx_3.8.4 vctrs_0.6.5 getip_0.1-4 [17] data.table_1.16.2 compiler_4.4.0 rstudioapi_0.16.0 tools_4.4.0 [21] pillar_1.10.1 Rcpp_1.0.13-1 rlang_1.1.4 

[shikokuchuo]

I get all query succeeded up to past 80,000 and then:

12:28:41.77 BEGIN dispatcher query loop 12:28:41.77 querying dispatcher query succeeded 12:28:41.98 END dispatcher query loop push 75000 of 1e+05 push 80000 of 1e+05 Error: ! crew task name unnamed_task_657f11f246b7 already found in the task list. Before pushing a task of the same name, please wait for it to resolve, then use pop() or collect() to remove it from the controller. > sessionInfo()

My versions are: mirai 2.0.1.9006 and nanonext 1.5.0. And your 'query' branch of crew of course.

[wlandau]

wlandau/crew@fa22fdf should avoid those conflicts among task names. I wonder if you get a timeout if you install that commit and increase the numbers of workers and tasks.

[shikokuchuo]

There's now the info() interface that guarantees returning either the result vector or else NULL, so this should be easier to handle.

[wlandau]

FYI: I just created a "sequential" crew controller for profiling purposes. This controller runs tasks in the interactive R session instead of parallel processes. On an M2 MacBook, it can run a million tasks in just over 2 minutes:

n <- 1e6L controller <- crew::crew_controller_sequential() # requires development crew controller$start() system.time({ for (index in seq_len(n)) { controller$push(TRUE) controller$pop() } while (controller$nonempty()) { controller$pop() } }) controller$terminate() #> user system elapsed  #> 135.783 5.871 142.074 

The local controller with 1 worker/daemon takes almost 7 minutes, which is still excellent, but the 4-minute overhead is worth noting.

n <- 1e6 controller <- crew::crew_controller_local() controller$start() system.time({ for (index in seq_len(n)) { controller$push(TRUE) controller$pop() } while (controller$nonempty()) { controller$pop() } }) controller$terminate() #> user system elapsed #> 368.451 58.468 406.116 

[shikokuchuo]

This is not comparable as you're not performing the same actions within the same process in your 'sequential' controller e.g. serializing and unserializing the data. I suspect most of the overhead lies there.

[wlandau]

This is not comparable as you're not performing the same actions within the same process in your 'sequential' controller e.g. serializing and unserializing the data.

You have a good point, that controller does not (un)serialize.

I suspect most of the overhead lies there.

Serialization happens in request() within mirai(), right? The profiling data in #198 (comment) actually shows query_dispatcher() takes slightly more time.

[wlandau]

The profiling data in #198 (comment) actually shows query_dispatcher() takes slightly more time.

Realizing I'd actually have to repeat this in crew because crew might not actually query the dispatcher as much.

[shikokuchuo]

mirai::daemons(sync = TRUE) will allow synchronous profiling, but there's overhead in setting that up and dynamically switching the global environment, so even that is probably not going to be much use as a comparison.

[shikokuchuo]

Thanks for sharing this. Recent improvements in mirai should have made this even better (notably the new info() interface), but if you notice any areas for improvement, I'd be happy to hear about it.