Use `session` in `log_shiny_input_changes` to detect testing environment and utilize namespaces for more informative logging

[m7pr]

trafficstars

Alternative approach for https://github.com/daroczig/logger/pull/154

Usage in tests

We enhanced log_shiny_input_changes so that it uses session object. This allows to detect if we are in the Mocked Shiny session - a type of the session used in shiny::testServer during {testthat} tests. This is needed so that tests using shiny::testServer do not fail due to:

library(shiny)
server <- function(input, output, session) {
  logger::log_shiny_input_changes()
  x <- reactive(input$a * input$b)
}

testServer(server, {
  session$setInputs(a = 2, b = 3)
  stopifnot(x() == 6)
})
Error in logger::log_shiny_input_changes() :
No Shiny app running, it makes no sense to call this function outside of a Shiny app

Distinction between modules

The ability of using session object allows to extract the current module's namespace. This is useful for logging, if you have multiple modules with the same input names. This way you can distinguish log-messages based on modules' namespaces.

Shiny App Code

# Define the UI for a module
counterUI <- function(id, label = "Counter") {
  ns <- NS(id)
  tagList(
    actionButton(ns("button"), label = label),
    verbatimTextOutput(ns("out"))
  )
}

# Define the server logic for a module
counterServer <- function(id) {
  moduleServer(
    id,
    function(input, output, session) {
      logger::log_shiny_input_changes(input)
      count <- reactiveVal(0)
      observeEvent(input$button, {
        count(count() + 1)
      })
      output$out <- renderText({
        count()
      })
      count
    }
  )
}

# Use the module in an app
ui <- fluidPage(
  counterUI("counter1", "Counter #1"),
  counterUI("counter2", "Counter #2")
)
server <- function(input, output, session) {
  counterServer("counter1")
  counterServer("counter2")
}
if (interactive()) {
  shinyApp(ui, server)
}

Output

Listening on http://127.0.0.1:6196
INFO [2024-05-14 14:18:09] counter1 Default Shiny inputs initialized: {"button":0}
INFO [2024-05-14 14:18:09] counter2 Default Shiny inputs initialized: {"button":0}
INFO [2024-05-14 14:18:17] Shiny input change detected in counter1 on button: 0 -> 1
INFO [2024-05-14 14:18:17] Shiny input change detected in counter2 on button: 1 -> 0
INFO [2024-05-14 14:18:18] Shiny input change detected in counter1 on button: 0 -> 2
INFO [2024-05-14 14:18:18] Shiny input change detected in counter2 on button: 2 -> 0
INFO [2024-05-14 14:18:19] Shiny input change detected in counter1 on button: 0 -> 3
INFO [2024-05-14 14:18:19] Shiny input change detected in counter2 on button: 3 -> 0
INFO [2024-05-14 14:18:19] Shiny input change detected in counter1 on button: 0 -> 4
INFO [2024-05-14 14:18:19] Shiny input change detected in counter2 on button: 4 -> 0
INFO [2024-05-14 14:18:19] Shiny input change detected in counter1 on button: 0 -> 5
INFO [2024-05-14 14:18:19] Shiny input change detected in counter2 on button: 5 -> 0

[m7pr]

CCing @daroczig for visibility

[daroczig]

Thanks a ton, looks very promising! Could you please take a look at the failing unit tests?

[m7pr]

@daroczig sure, just made one change, can you approve workflows to run again?

[m7pr]

CC @daroczig sure, just made one change, can you approve workflows to run again?

[daroczig]

sorry for the delay with getting back to this :facepalm:

I've rerun the unit tests, but seeing the same error:

── Failure ('test-CRANSKIP-hooks.R:101:5'): shiny input change is logged with different level ──
`obs` does not match "ERROR \\[[0-9: \\-]+\\] Shiny input change detected on a: NULL -> 2".
Actual value: "INFO \[2024-07-31 21:49:35\] Loading required package: shiny\\nLoading required package: shiny\\nERROR \[2024-07-31 21:49:36\] mock-session Default Shiny inputs initialized: \{\}\\nERROR \[2024-07-31 21:49:36\] mock-session Shiny input change detected in a: NULL -> 2"

can you please update the related unit test(s)?

[m7pr]

Sorry @daroczig for the delay. I fixed the mentioned test.

[daroczig]

since then, we switched using snapshots for testing, so that's causing some git conflict -- I'm looking into it