From c7ca49c634242340ab3494396217885f00ed323f Mon Sep 17 00:00:00 2001
From: Garrick Aden-Buie <garrick@adenbuie.com>
Date: Tue, 24 Sep 2024 20:44:31 -0400
Subject: [PATCH] debug: Add debugging messages for debounce/throttle test

---
 tests/testthat/test-reactivity.r | 11 ++++++++++-
 1 file changed, 10 insertions(+), 1 deletion(-)

diff --git a/tests/testthat/test-reactivity.r b/tests/testthat/test-reactivity.r
index fb36be1926..bd7eab4d7b 100644
--- a/tests/testthat/test-reactivity.r
+++ b/tests/testthat/test-reactivity.r
@@ -1245,6 +1245,7 @@ test_that("debounce/throttle work properly (with priming)", {
   src <- observe({
     invalidateLater(100)
     rv$a <- isolate(rv$a) + 1
+    message(the_time(), "input ", isolate(rv$a))
   })
   on.exit(src$destroy(), add = TRUE)
 
@@ -1258,12 +1259,14 @@ test_that("debounce/throttle work properly (with priming)", {
   dr_fired <- 0
   dr_monitor <- observeEvent(dr(), {
     dr_fired <<- dr_fired + 1
+    message(the_time(), "debounced ", dr_fired)
   })
   on.exit(dr_monitor$destroy(), add = TRUE)
 
   tr_fired <- 0
   tr_monitor <- observeEvent(tr(), {
     tr_fired <<- tr_fired + 1
+    message(the_time(), "throttle ", tr_fired)
   })
   on.exit(tr_monitor$destroy(), add = TRUE)
 
@@ -1277,12 +1280,16 @@ test_that("debounce/throttle work properly (with priming)", {
   }
 
   # Pump timer and reactives for about 1.3 seconds
-  stopAt <- Sys.time() + 1.3
+  start_time <- Sys.time()
+  the_time <- function() sprintf("%0.5f ", Sys.time() - start_time)
+  message(the_time(), "==== start [run for 1.3s]")
+  stopAt <- start_time + 1.3
   while (Sys.time() < stopAt) {
     timerCallbacks$executeElapsed()
     flushReact()
     Sys.sleep(0.001)
   }
+  message(the_time(), "==== end [run for 1.3s]")
 
   # dr() should not have had time to fire, other than the initial run, since
   # there haven't been long enough gaps between invalidations.
@@ -1297,11 +1304,13 @@ test_that("debounce/throttle work properly (with priming)", {
   # Now let some time pass without any more updates.
   src$destroy() # No more updates
   stopAt <- Sys.time() + 1
+  message(the_time(), "==== start [finish running]")
   while (Sys.time() < stopAt) {
     timerCallbacks$executeElapsed()
     flushReact()
     Sys.sleep(0.001)
   }
+  message(the_time(), "==== end [finish running]")
 
   # dr should've fired, and we should have converged on the right answer.
   expect_identical(dr_fired, 2)