HenrikBengtsson/progressr

The first progress handler muffles the others in the very last step

HenrikBengtsson opened this issue · 0 comments

Issue

The first progress handler muffles the others in the very last step. For example, with:

library(progressr)
handlers(global = TRUE)
options(progressr.clear = FALSE)

clean <- function(n = 5L) {
  p <- progressor(steps = n)
  for (kk in seq_len(n)) {
    Sys.sleep(0.1)
    p(message = sprintf("Step #%d", kk))
  }
}

we get:

handlers(c("debug", "progress", "newline"))
clean()

outputs:

[11:35:08.551] (0.000s => +0.002s) initiate: 0/5 (+0) '' {clear=FALSE, enabled=TRUE, status=}
- [------------------------------------------------------------------------------------------------------------------------]   0% 
[11:35:08.655] (0.104s => +0.001s) update: 1/5 (+1) 'Step #1' {clear=FALSE, enabled=TRUE, status=}
\ [======================>------------------------------------------------------------------------------------------]  20% Step #1
[11:35:08.759] (0.208s => +0.001s) update: 2/5 (+1) 'Step #2' {clear=FALSE, enabled=TRUE, status=}
| [============================================>--------------------------------------------------------------------]  40% Step #2
[11:35:08.862] (0.311s => +0.001s) update: 3/5 (+1) 'Step #3' {clear=FALSE, enabled=TRUE, status=}
/ [===================================================================>---------------------------------------------]  60% Step #3
[11:35:08.965] (0.415s => +0.001s) update: 4/5 (+1) 'Step #4' {clear=FALSE, enabled=TRUE, status=}
- [=========================================================================================>-----------------------]  80% Step #4
[11:35:09.069] (0.518s => +0.001s) update: 5/5 (+1) 'Step #5' {clear=FALSE, enabled=TRUE, status=}
[11:35:09.069] (0.519s => +0.001s) update: 5/5 (+0) 'Step #5' {clear=FALSE, enabled=TRUE, status=}

Note how the 'debug' handler reports on the last step, but not the 'progress' bar.

Vice versa:

handlers(c("progress", "newline", "debug"))
clean()

outputs:

- [------------------------------------------------------------------------------------------------------------------------]   0% 
[11:35:09.076] (0.000s => +0.004s) initiate: 0/5 (+0) '' {clear=FALSE, enabled=TRUE, status=}
\ [======================>------------------------------------------------------------------------------------------]  20% Step #1
[11:35:09.180] (0.103s => +0.003s) update: 1/5 (+1) 'Step #1' {clear=FALSE, enabled=TRUE, status=}
| [============================================>--------------------------------------------------------------------]  40% Step #2
[11:35:09.283] (0.206s => +0.002s) update: 2/5 (+1) 'Step #2' {clear=FALSE, enabled=TRUE, status=}
/ [===================================================================>---------------------------------------------]  60% Step #3
[11:35:09.386] (0.310s => +0.002s) update: 3/5 (+1) 'Step #3' {clear=FALSE, enabled=TRUE, status=}
- [=========================================================================================>-----------------------]  80% Step #4
[11:35:09.489] (0.413s => +0.002s) update: 4/5 (+1) 'Step #4' {clear=FALSE, enabled=TRUE, status=}
\ [=================================================================================================================] 100% Step #5

Note how the 'progress' bar reports on the last step, but not the 'debug' handler.

More

This is the case when using both handlers(global = TRUE) and with_progress(clean()).