r-lib / later

Schedule an R function or formula to run after a specified period of time.
https://r-lib.github.io/later
Other
137 stars 27 forks source link

Private event loop behaves differently when executed within block #174

Open DavorJ opened 1 year ago

DavorJ commented 1 year ago

Let's define this function and event loop:

fn <- function() print(Sys.time())
tloop <- later::create_loop()

If I execute a block of code like this, then fn gets exxecuted:

> {print(Sys.time()); later::later(fn, delay = 2, loop = tloop); Sys.sleep(5)}
[1] "2023-05-14 11:19:17 UTC"
[1] "2023-05-14 11:19:23 UTC"

But if I execute line by line (important!), I get this:

> print(Sys.time())
[1] "2023-05-14 11:21:16 UTC"
> later::later(fn, delay = 2, loop = tloop)
> Sys.sleep(5)

Why does the fn execute in first case, but not in the second case? Is this by design, or a bug?

In the second case, fn would be execueted only if 2 seconds pass and either:

wch commented 1 year ago

It doesn't behave that way for me -- in the second case, it still prints out the time after 5 seconds. It does the same on my mac in both RStudio and in a terminal. (Note that I stepped through each line for the second case.)

> fn <- function() print(Sys.time())
> tloop <- later::create_loop()
> {
+   print(Sys.time())
+   later::later(fn, delay = 2, loop = tloop)
+   Sys.sleep(5)
+ }
[1] "2023-05-14 09:49:08 CDT"
[1] "2023-05-14 09:49:13 CDT"
> print(Sys.time())
[1] "2023-05-14 09:49:22 CDT"
> later::later(fn, delay = 2, loop = tloop)
> Sys.sleep(5)
[1] "2023-05-14 09:49:28 CDT"

Can you provide the output of sessioninfo::session_info()? This is mine:

> sessioninfo::session_info()
─ Session info ─────────────────────────────────────────────────────────────────────
 setting  value
 version  R version 4.2.2 (2022-10-31)
 os       macOS Ventura 13.2.1
 system   aarch64, darwin20
 ui       RStudio
 language (EN)
 collate  en_US.UTF-8
 ctype    en_US.UTF-8
 tz       America/Chicago
 date     2023-05-14
 rstudio  2023.05.0-daily+19 Mountain Hydrangea (desktop)
 pandoc   3.1.2 @ /opt/homebrew/bin/pandoc

─ Packages ─────────────────────────────────────────────────────────────────────────
 package     * version date (UTC) lib source
 cli           3.6.1   2023-03-23 [1] CRAN (R 4.2.0)
 later         1.3.0   2021-08-18 [1] CRAN (R 4.2.0)
 Rcpp          1.0.10  2023-01-22 [1] CRAN (R 4.2.0)
 rlang         1.1.1   2023-04-28 [1] CRAN (R 4.2.0)
 rstudioapi    0.14    2022-08-22 [1] CRAN (R 4.2.0)
 sessioninfo   1.2.2   2021-12-06 [1] CRAN (R 4.2.0)

 [1] /Users/winston/R/4.2
 [2] /Library/Frameworks/R.framework/Versions/4.2-arm64/Resources/library

────────────────────────────────────────────────────────────────────────────────────
DavorJ commented 1 year ago

@wch, here is sessionInfo() from which the original code was executed:

R version 3.6.3 (2020-02-29)
Platform: x86_64-w64-mingw32/x64 (64-bit)
Running under: Windows 10 x64 (build 19044)

Matrix products: default

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

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

other attached packages:
[1] assertthat_0.2.1

loaded via a namespace (and not attached):
 [1] Rcpp_1.0.7      roxygen2_7.1.2  later_1.3.0     R6_2.5.1        jsonlite_1.7.2  magrittr_2.0.1  rlang_1.0.4     stringi_1.7.6   shrtcts_0.1.2   cli_3.3.0      
[11] renv_0.13.2     rstudioapi_0.13 fs_1.5.2        xml2_1.3.3      tools_3.6.3     stringr_1.4.0   purrr_0.3.4     compiler_3.6.3  xfun_0.31       knitr_1.36

I also tried on R v4.0.5 on console:

R version 4.0.5 (2021-03-31) -- "Shake and Throw"
Copyright (C) 2021 The R Foundation for Statistical Computing
Platform: x86_64-w64-mingw32/x64 (64-bit)

R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.

R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.

Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.

> fn <- function() print(Sys.time())
> tloop <- later::create_loop()
> {print(Sys.time()); later::later(fn, delay = 2, loop = tloop); Sys.sleep(5)}
[1] "2023-05-14 19:07:55 CEST"
> [1] "2023-05-14 19:08:01 CEST"

> sessionInfo()
R version 4.0.5 (2021-03-31)
Platform: x86_64-w64-mingw32/x64 (64-bit)
Running under: Windows 10 x64 (build 19044)

Matrix products: default

locale:
[1] LC_COLLATE=Dutch_Belgium.1252  LC_CTYPE=Dutch_Belgium.1252
[3] LC_MONETARY=Dutch_Belgium.1252 LC_NUMERIC=C
[5] LC_TIME=Dutch_Belgium.1252

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

loaded via a namespace (and not attached):
[1] compiler_4.0.5 later_1.3.0    Rcpp_1.0.8.3   rlang_1.0.2
>

Closed the console, then opened again;

R version 4.0.5 (2021-03-31) -- "Shake and Throw"
Copyright (C) 2021 The R Foundation for Statistical Computing
Platform: x86_64-w64-mingw32/x64 (64-bit)

R is free software and comes with ABSOLUTELY NO WARRANTY.
You are welcome to redistribute it under certain conditions.
Type 'license()' or 'licence()' for distribution details.

R is a collaborative project with many contributors.
Type 'contributors()' for more information and
'citation()' on how to cite R or R packages in publications.

Type 'demo()' for some demos, 'help()' for on-line help, or
'help.start()' for an HTML browser interface to help.
Type 'q()' to quit R.

> fn <- function() print(Sys.time())
> tloop <- later::create_loop()
> print(Sys.time())
[1] "2023-05-14 19:08:53 CEST"
> later::later(fn, delay = 2, loop = tloop)
> Sys.sleep(5)
> sessionInfo()
R version 4.0.5 (2021-03-31)
Platform: x86_64-w64-mingw32/x64 (64-bit)
Running under: Windows 10 x64 (build 19044)

Matrix products: default

locale:
[1] LC_COLLATE=Dutch_Belgium.1252  LC_CTYPE=Dutch_Belgium.1252
[3] LC_MONETARY=Dutch_Belgium.1252 LC_NUMERIC=C
[5] LC_TIME=Dutch_Belgium.1252

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

loaded via a namespace (and not attached):
[1] compiler_4.0.5 later_1.3.0    Rcpp_1.0.8.3   rlang_1.0.2
> later::run_now(loop=tloop)
[1] "2023-05-14 19:09:38 CEST"
>
wch commented 1 year ago

Thanks for the info. I wonder if it x Does it happen when you run the code without a private event loop, like this?

fn <- function() print(Sys.time())

{
  print(Sys.time())
  later::later(fn, delay = 2)
  Sys.sleep(5)
}

print(Sys.time())
later::later(fn, delay = 2)
Sys.sleep(5)

This is what I see:

> fn <- function() print(Sys.time())
> {
+   print(Sys.time())
+   later::later(fn, delay = 2)
+   Sys.sleep(5)
+ }
[1] "2023-05-14 12:40:36 CDT"
[1] "2023-05-14 12:40:41 CDT"
> print(Sys.time())
[1] "2023-05-14 12:40:42 CDT"
> later::later(fn, delay = 2)
> Sys.sleep(5)
[1] "2023-05-14 12:40:49 CDT"
DavorJ commented 1 year ago

Then I get the same as you yes. This is what I expect from a global event loop, but I don't understand exactly how a private loop should behave.

I'll omit a printout to keep the thread readable, but if you need it let me know.

wch commented 1 year ago

When a loop is created with create_loop(), the current event loop should be its parent. Normally, the parent would be the global event loop.

When a parent loop runs, it runs its children. So the behavior that I see is what I would expect. I don't know why yours is behaving that way.

When you restart and run later::current_loop(), it should print something like this, with ID 0:

> later::current_loop()
<event loop> ID: 0
> later::global_loop()
<event loop> ID: 0
wch commented 1 year ago

@DavorJ I finally dug out my Windows machine and tested on it, and I get the same result as you, so it seems likely that there's something not right about how we do things on Windows.

DavorJ commented 1 year ago

Here is an odd case that may be helpful in understanding what happens on Windows:

object <- function() {

  CANCEL <- function() NULL
  # LOOP <- later::global_loop()
  LOOP <- later::create_loop(parent = later::global_loop())
  i <- 0L

  task <- function() {
    print(i <<- i + 1) 
    Sys.sleep(1)
    CANCEL <<- later::later(schedule, loop = LOOP)
  }

  schedule <- function() {
    if (i < 30L) CANCEL <<- later::later(task, loop = LOOP)
  }

  destroy <- function(envir) {later::destroy_loop(LOOP)}

  reg.finalizer(e = environment(), f = destroy, onexit = TRUE)

  list(
    'start' = function() schedule(),
    'cancel' = function() CANCEL(),
    'wait' = function() {
      print('Waiting...')
      while (!later::loop_empty(loop = LOOP)) {
        later::run_now(timeoutSecs = -1, loop = LOOP)
      }
      print('Done...')
    } 
  )
}

obj <- object()
obj$start()
# [1] 1
# [1] 2
# [1] 3
# [1] 4
# [1] 5
# [1] 6
# [1] 7
# [1] 8
# [1] 9
# [1] 10

This should count to 30. Oddly, on Windows it counts to 10 only, then stops. You can execute later::run_now() to let it continue with another 10.

Replacing LOOP with global loop will behave correctly and will count to 30. You kan make it run faster by reducing the Sys.sleep() to e.g. 0.01 sec: makes no difference.