log_separator breaks logging to file when called within reactive context in shiny apps

[MSHelm]

Hi,

I started using logger for logging with my shiny app. It works great when logging to the console, but when logging to a file I have some troubles with log_separator. My intended behavior is: The user can selected some inputs (x and y in below examples). Once both are selected I want to start logging to a new file. When the user selects a new combination I want to start a new file. I.e. for every valid selection I want to have a separate log file with all all steps done for it.

Below example works completely fine when logging to console. But as soon as I switch to logging to file, the logging only runs until log_info("This still works") and then throws the error Warning: Error in force: object 'my_log_path' not found. Note that the log file is created initially and written to, only everything starting from the separator on is not logged. Removing log_separator() fixes the issue.

I am a bit at a loss unfortunately and would appreciate any feedback on how to fix this issue. I also tried creating the log path in a separate observer but this throws the same error.

Reproducible example

library(shiny)
library(logger)

ui <- fluidPage(
      textInput("x", "Enter X"),
      textInput("y", "Enter Y"),
      textOutput("out")
)

server <- function(input, output) {
    z <- reactive({
      req(input$x, input$y)
      my_log_path <- paste0(Sys.time(), "_", input$x, "_", input$y, ".log")
      log_appender(appender_file(my_log_path))
      log_info("Starting Analysis")
      log_info("This still works")
      log_separator()
      log_info("This is never reached")
      paste("You wrote", input$x, "and", input$y)
    })

    output$out <- renderText(z())
}

shinyApp(ui = ui, server = server)

Session info

``` r R version 4.1.3 (2022-03-10) Platform: x86_64-pc-linux-gnu (64-bit) Running under: Ubuntu 20.04.6 LTS Matrix products: default BLAS: /usr/lib/x86_64-linux-gnu/openblas-pthread/libblas.so.3 LAPACK: /usr/lib/x86_64-linux-gnu/openblas-pthread/liblapack.so.3 locale: [1] LC_CTYPE=en_US.UTF-8 LC_NUMERIC=C [3] LC_TIME=en_US.UTF-8 LC_COLLATE=en_US.UTF-8 [5] LC_MONETARY=en_US.UTF-8 LC_MESSAGES=en_US.UTF-8 [7] LC_PAPER=en_US.UTF-8 LC_NAME=C [9] LC_ADDRESS=C LC_TELEPHONE=C [11] LC_MEASUREMENT=en_US.UTF-8 LC_IDENTIFICATION=C attached base packages: [1] stats graphics grDevices datasets utils methods base other attached packages: [1] logger_0.3.0 shiny_1.8.1.1 loaded via a namespace (and not attached): [1] Rcpp_1.0.12 crayon_1.5.2 digest_0.6.35 later_1.3.2 [5] mime_0.12 R6_2.5.1 jsonlite_1.8.8 lifecycle_1.0.4 [9] xtable_1.8-4 magrittr_2.0.3 cachem_1.0.8 rlang_1.1.3 [13] cli_3.6.2 renv_1.0.3 promises_1.3.0 jquerylib_0.1.4 [17] bslib_0.7.0 tools_4.1.3 glue_1.7.0 httpuv_1.6.15 [21] fastmap_1.1.1 compiler_4.1.3 memoise_2.0.1 htmltools_0.5.8.1 [25] sass_0.4.9 ```

[daroczig]

Could you please test with the main branch? A fix was just published for #157 with a very similar issue.

[MSHelm]

@daroczig The issue unfortunately still exists, with the same error. As a workaround I am currently using the following snippet, which works as intended. Maybe that helps for debugging:

my_log_separator <- function() {
  logger::log_info("{paste0(rep('=', 80), collapse = '')}")
}