Terminal color stuck after displaying progress bar

matthiasgomolka commented 2 years ago

Hi Henrik,

first of all, many thanks for progressr, It's really useful!

I have a problem which I fail to reproduce in a reprex. But maybe the issue is known and someone can help anyways.

Here's what I'm doing: I have a long running function which gives status updates at certain points using cli::cli_alert_info(). At some point in the function I iterate over many files using future.apply::future_lapply(). Within this step, I display a progress bar using progressr. Afterwards, more messages via cli::cli_alert_*() follow.

In principle, everything works fine, but after displaying the progress bar, the cli messages are displayed in the default color for messages and do not respect the cli formatting any more.

Here is a screenshot: (The progress bar was displayed before the Compressing ... message.)

In principle, what I do is similar to this:

library(progressr)
library(progress)
library(cli)

slow_sqrt_sub <- function(x, p) {
    Sys.sleep(0.5)
    p(sprintf("x=%g", x))
    sqrt(x)
}

slow_sqrt <- function(xs) {
    cli_alert_info("Starting {.fn slow_sqrt}")
    p <- progressor(along = xs)
    lapply(xs, slow_sqrt_sub, p = p)
    cli_alert_success("Finished {.fn slow_sqrt}")
}

slow_sqrt(1:10)

But in this minimal example, everything works fine. As far as I understand, everything about the progress bar is identical in both my real use case and the minimal example.

I'm thankful for any hints!

If #123 comes true, this should become irrelevant, because I would switch to the cli handler.

HenrikBengtsson commented 2 years ago

Thanks for the report, and I'm happy you like it.

I guess you're also using handlers("progress")here, correct?

You mention future.apply::future_lapply() but in your example, which doesn't reproduce them problem, you use lapply(). Does it reproduce if you use plan(sequential) - assuming you run with some parallel backend normally? Does it reproduce if you replace future.apply::future_lapply() with lapply()?

Does this happen in terminal R, in RStudio Console, or both?

If you can come up with a reproducible example, that will make it much more likely that'll be fixed quickly.

Can you please share your sessionInfo() when this happens? That'll also help narrow in on the problem, and reproduce it.

HenrikBengtsson commented 2 years ago

For your screenshots, you can also try running with options(progressr.clear=FALSE). That should leave the last rendering of the progress bar intact (without clearing it), so one can see what it shows at that time. What puzzles me is that handlers("progress") should not set or use ANSI colors, so I cannot see how it can introduce a red foreground color here.

matthiasgomolka commented 2 years ago

Sorry for the incomplete report.

I also tried the minimal example with future_lapply() and it worked as expected. I stripped that for the sake of simplicity.
I also tried my real use case without handlers("progress") and it still did not work as expected.
I ran the function in terminal R as well, same problem:
What I did observe is that when I use with_progress(...) instead of handlers(global = TRUE), there is no cli coloring at all.

Now I'm trying to tear my real use case down, hoping to find the issue.

Here is the session info:

> sessionInfo()
R version 4.0.2 (2020-06-22)
Platform: x86_64-w64-mingw32/x64 (64-bit)
Running under: Windows 10 x64 (build 19042)

Matrix products: default

locale:
[1] LC_COLLATE=German_Germany.1252  LC_CTYPE=German_Germany.1252    LC_MONETARY=German_Germany.1252
[4] LC_NUMERIC=C                    LC_TIME=German_Germany.1252    

attached base packages:
[1] stats     graphics  grDevices utils     datasets  methods   base     

other attached packages:
[1] archivR_1.0.0.7 testthat_3.1.2  devtools_2.4.3  usethis_2.1.5  

loaded via a namespace (and not attached):
 [1] progress_1.2.2     tidyselect_1.1.1   remotes_2.4.2      purrr_0.3.4        listenv_0.8.0     
 [6] vctrs_0.3.8        utf8_1.2.2         rlang_0.4.11       pkgbuild_1.3.1     pillar_1.6.2      
[11] glue_1.4.2         withr_2.4.3        bit64_4.0.5        sessioninfo_1.2.2  lifecycle_1.0.0   
[16] progressr_0.10.0   zip_2.2.0          future_1.23.0      codetools_0.2-18   memoise_2.0.1     
[21] arrow_5.0.0.2      callr_3.7.0        tzdb_0.1.2         fastmap_1.1.0      ps_1.6.0          
[26] parallel_4.0.2     fansi_0.5.0        readr_2.0.1        backports_1.2.1    checkmate_2.0.0   
[31] cachem_1.0.6       writexl_1.3.1      desc_1.4.0         pkgload_1.2.4      parallelly_1.30.0 
[36] fs_1.5.0           bit_4.0.4          brio_1.1.0         hms_1.1.0          digest_0.6.27     
[41] stringi_1.7.3      processx_3.5.2     rprojroot_2.0.2    cli_3.1.1          tools_4.0.2       
[46] magrittr_2.0.1     tibble_3.1.4       crayon_1.4.1       future.apply_1.8.1 pkgconfig_2.0.3   
[51] ellipsis_0.3.2     data.table_1.14.0  prettyunits_1.1.1  assertthat_0.2.1   rstudioapi_0.13   
[56] R6_2.5.0           globals_0.14.0     compiler_4.0.2

matthiasgomolka commented 2 years ago

I still have no minimal reprex, but I simplified my use case so that I found out that it works fine when I set future::plan("multisession") but shows to problem as above when I set future::plan("sequential").

When I don't set any future plan, it also works.

HenrikBengtsson commented 2 years ago

Was your first screenshot (white background) from the RStudio Console?

That would make sense given your screenshot from the terminal; in RStudio stderr output is in red, whereas in the terminal it is white. This would tell me that the red color is not from cli, but from RStudio. Thus, then my guess is that something completely disables ANSI colors (whereas before I thought something set it to red first).

HenrikBengtsson commented 2 years ago

I still have no minimal reprex, but I simplified my use case so that I found out that it works fine when I set future::plan("multisession") but shows to problem as above when I set future::plan("sequential").

When I don't set any future plan, it also works.

Did you mix up 'multisession' and 'sequential' above? Because, if you don't set plan(), the default is plan(sequential), but your comments say these two behaves differently, which doesn't add up for me

HenrikBengtsson commented 2 years ago

You know what, are you sure it's related to progressr? Maybe you get the same if you drop all the progressr-relates code? Can you retry after dropping the progressed code? (Something tells me that's actually the case)

matthiasgomolka commented 2 years ago

Was your first screenshot (white background) from the RStudio Console?

That would make sense given your screenshot from the terminal; in RStudio stderr output is in red, whereas in the terminal it is white. This would tell me that the red color is not from cli, but from RStudio. Thus, then my guess is that something completely disables ANSI colors (whereas before I thought something set it to red first).

Yes, the first screenshot is from RStudio Console. Red is the default color for messages in my theme.

matthiasgomolka commented 2 years ago

I still have no minimal reprex, but I simplified my use case so that I found out that it works fine when I set future::plan("multisession") but shows to problem as above when I set future::plan("sequential"). When I don't set any future plan, it also works.

Did you mix up 'multisession' and 'sequential' above? Because, if you don't set plan(), the default is plan(sequential), but your comments say these two behaves differently, which doesn't add up for me

Neither to me, but this is what I observed. It works if I set no future::plan(), but once I set any future::plan(), it only works with future::plan("multisession").

matthiasgomolka commented 2 years ago

You know what, are you sure it's related to progressr? Maybe you get the same if you drop all the progressr-relates code? Can you retry after dropping the progressed code? (Something tells me that's actually the case)

I'm pretty sure it's related to the progress bar. When I set progressr::handlers(global = FALSE) to disable the progress bar, all output is fine.

HenrikBengtsson commented 2 years ago

Yes, the first screenshot is from RStudio Console. Red is the default color for messages in my theme.

Perfect, because that rules out a lot of things.

Neither to me, but this is what I observed. It works if I set no future::plan(), but once I set any future::plan(), it only works with future::plan("multisession").

Hmm, weird. If you do not set a plan(), you should get 'sequential' by default. I think this needs to be sorted out / ruled out first. If you do get different behavior where I expect them to be the same, that might also be a lead. What do you get if you do:

library(future)

## Show the default plan
p0 <- plan()
print(p0)
#> sequential:
#> - args: function (..., envir = parent.frame())
#> - tweaked: FALSE
#> - call: NULL

## Show the plan after setting it to sequential
plan(sequential)
p1 <- plan()
print(p1)
#> sequential:
#> - args: function (..., envir = parent.frame())
#> - tweaked: FALSE
#> - call: plan(sequential)

## Show the plan after setting it to multisession
plan(multisession)
p2 <- plan()
print(p2)
#> multisession:
#> - args: function (..., workers = availableCores(), lazy = FALSE, rscript_libs = .libPaths(), envir = parent.frame())
#> - tweaked: FALSE
#> - call: plan(multisession)

I'm pretty sure it's related to the progress bar. When I set progressr::handlers(global = FALSE) to disable the progress bar, all output is fine.

Got it. Thanks for (re-)confirming.

matthiasgomolka commented 2 years ago

Hmm, weird. If you do not set a plan(), you should get 'sequential' by default. I think this needs to be sorted out / ruled out first. If you do get different behavior where I expect them to be the same, that might also be a lead. What do you get if you do:
...

Here is what I get:

library(future)
#> Warning: package 'future' was built under R version 4.0.5

## Show the default plan
p0 <- plan()
print(p0)
#> sequential:
#> - args: function (..., envir = parent.frame())
#> - tweaked: FALSE
#> - call: NULL

## Show the plan after setting it to sequential
plan(sequential)
p1 <- plan()
print(p1)
#> sequential:
#> - args: function (..., envir = parent.frame())
#> - tweaked: FALSE
#> - call: plan(sequential)

## Show the plan after setting it to multisession
plan(multisession)
p2 <- plan()
print(p2)
#> multisession:
#> - args: function (..., workers = availableCores(), lazy = FALSE, rscript_libs = .libPaths(), envir = parent.frame())
#> - tweaked: FALSE
#> - call: plan(multisession)

^{Created on 2022-02-16 by the reprex package (v0.3.0)}

HenrikBengtsson commented 1 year ago

I'm revisiting this one. I don't think I can do anything without a reproducible example, at least an example that is reproducible on your end. At this point, the problem can be due to your settings, the progress package, the cli package, the progressr package, or something else.

I'm closing this one, but please report back if you can give some more clues on what's going on. If someone else sees this, please post a comment too.

futureverse / progressr

Terminal color stuck after displaying progress bar #134