profiling mirai 2.0.0
#198
Replies: 2 comments 10 replies
-
|
With https://github.com/wlandau/crew/tree/193, I've hit cases where |
Beta Was this translation helpful? Give feedback.
-
Could it be that the dispatcher just is too busy dispatching tasks to find a free moment to respond to the status query? |
Beta Was this translation helpful? Give feedback.
-
|
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 |
Beta Was this translation helpful? Give feedback.
-
|
It's small data, and the frequency of dispatcher queries depends on connection/disconnection events and 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 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 |
Beta Was this translation helpful? Give feedback.
-
|
I get all 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. |
Beta Was this translation helpful? Give feedback.
-
|
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. |
Beta Was this translation helpful? Give feedback.
-
|
FYI: I just created a "sequential" 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 |
Beta Was this translation helpful? Give feedback.
-
|
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. |
Beta Was this translation helpful? Give feedback.
-
You have a good point, that controller does not (un)serialize.
Serialization happens in |
Beta Was this translation helpful? Give feedback.
-
Realizing I'd actually have to repeat this in |
Beta Was this translation helpful? Give feedback.
-
Just thought I'd share a profiling study and data for
mirai2.0.0. I stress testedmiraion 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.
And here is the
pprofflame graph showing where the code spends most of its time:Beta Was this translation helpful? Give feedback.
All reactions