Drop in computation speed when integreating progress bar in package

[M-E-Rademaker]

Hi Henrik,

First thanks for the awesome package! I've been waiting since this issue popped up for a simple progressbar-API like the one you provide!

I am developing a package myself. I use future_lapply() in my package and now I
integrated the progressr package as well.

The relevant code snipped where I use these functions looks like this:

progressr::with_progress({
  progress_bar_csem <- progressr::progressor(along = 1:.R)
  Est_ls <- future.apply::future_lapply(1:.R, function(i) {
    progress_bar_csem(message = sprintf("Resample run = %g", i))
     # some code that performs resampling ...
  })  
})

It can be found here from line 752 onwards.

Now, if I run the function that triggers this piece of code using "multiprocess", I see a massive drop in speed compared to before I added the progessr functions with_progressbar/progressor/progress_bar_csem .

---

To replicate

1. Download and install the progress-bar branch from Github:
   devtools::install_github("M-E-Rademaker/cSEM", ref = "progress-bar")
2. Run this in R:

model <- "
# Structural model
eta2 ~ eta1
eta3 ~ eta1 + eta2

# Measurement
eta1 =~ y11 + y12 + y13
eta2 =~ y21 + y22 + y23
eta3 =~ y31 + y32 + y33
"

res <- csem(threecommonfactors, model, .resample_method = "bootstrap", .R = 5000,
                    .eval_plan = "multiprocess")

Note that (contray to your recommendation :-)) I integrated the evaluation plan in the package so users choose between "sequential" and "multiprocess" via the argument ".eval_plan".

I ran this code on Windows with an Intel i7-8565U 1,8GHz (4 physical/logical cores). When I open the resource monitor, all 8 logical cores begin, after a couple of seconds, to work at 100 %. The progress bar starts as expected. But when the progress bar reaches roughly 40% there is a sudden drop in the CPU-usage and the cores work at 0-10% (so essentially stop working). The progess bar continues and after some time the function returns its output correctly.

When you run the same code using the master branch of the cSEM package (or the version from CRAN: install.packages("cSEM")) without the progess bar, the example computes much faster without the sudden drop in CPU usage.

A thought:

• It think without the progress bar, the computation took roughly as long as the progress bar needs to reach 40 %. This is when the CPUs have their drop in usage. Maybe the computation is actually finished at 40% but the progress bar somehow continues??!

[HenrikBengtsson]

Sorry for the late reply. So, it turns out that ...

Note that (contray to your recommendation :-)) I integrated the evaluation plan in the package so users choose between "sequential" and "multiprocess" via the argument ".eval_plan".

prevents me and anyone else from even trying to reproduce your problem on a non-Windows machine. The thing is that 'multiprocess' resolves to multisession futures on Windows and multicore futures on Linux/macOS. So, things work just fine on Linux. (Kudos for resetting the plan() internally though)

However, I can speculate: With multisession workers, which really are {parallel}'s PSOCK cluster nodes, each progress update is sent back to the main R session via a socket connection as they are created, i.e. each time you call progress_bar_csem() in your loop. It could be that you're simply clogging up this communication channel by sending 5,000 conditions over a short period of time (~15 seconds on my 8 core laptop). If this is the problem, limiting the frequency of progress updates should mitigate the problem, e.g. try with:

    if (i %% 10 == 0) progress_bar_csem(message = sprintf("Resample run = %g", i))

to signal progress for every 10:th steps.

[HenrikBengtsson]

To try my hypothesis of too-many-progress-updates sent in a short period of time, which I would bet my money on, you could also disable the immediate signaling in this case by using:

options(future.psock.relay.immediate = FALSE)

and see if it runs faster. Note that that option is an internal option only available for testing and troubleshooting, so it's nothing that should be relied upon anywhere.

[HenrikBengtsson]

Maybe the computation is actually finished at 40% but the progress bar somehow continues??!

Only noticed this point right now; yes, that would make sense and would fit with the hypothesis of a clogged up communication channel.

[M-E-Rademaker]

Hi Henrik,

nice! Sending only every 10th request did the trick. Thank for the hint. I wasnt aware that this communication channel is so vulnerable - let alone, did I understand what is really going on under the hood.

Thanks again for all the effort, your work is appreciated - heavily!

[HenrikBengtsson]

Glad to hear. For now, I've added a section 'Note of caution - sending progress updates too frequently' to the vignette and the README. I've also created Issue #81 to bring this "workaround" in to the progressor() function itself.