daroczig / logger

A lightweight, modern and flexible, log4j and futile.logger inspired logging utility for R
https://daroczig.github.io/logger
285 stars 42 forks source link

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

Closed m7pr closed 2 months ago

m7pr commented 4 months ago

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 ```r # 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 commented 4 months ago

CCing @daroczig for visibility

daroczig commented 3 months ago

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

m7pr commented 3 months ago

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

m7pr commented 2 months ago

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

daroczig commented 2 months ago

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 commented 2 months ago

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

daroczig commented 2 months ago

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