13  Logging

Published

2025-02-09

Warning

The contents for this section are under development. Thank you for your patience.


Logging is essential for debugging and monitoring apps, helping track errors, warnings, and user activity. validate() ensures valid inputs and tryCatch() can catch unexpected errors in reactive expressions and log them instead of crashing the app.

The logger package provides structured logging, allowing us to save logs to files, console, or external services.

Key Benefits:

  1. Aids debugging by capturing detailed error messages and execution flow.

  2. Improves user experience by preventing unexpected crashes and providing informative error messages.

  3. Enables performance monitoring by logging app usage patterns and slow operations.

A proactive method for debugging Shiny applications is implementing logging. Logs are essential for debugging, auditing, and monitoring, particularly in Shiny app development and R packages. This chapter discusses integrating logging into a Shiny app-package to improve debugging and issue-tracking efficiency.

I’ve created the shinypak R package in an effort to make each section accessible and easy to follow. Install shinypak using pak (or remotes):

install.packages('pak')
pak::pak('mjfrigaard/shinypak')
library(shinypak)

List the apps in this chapter:

list_apps(regex = '13')

Launch apps with launch()

launch(app = '13_logging')

Download apps with get_app()

get_app(app = '13_logging')

13.1 Why Use Logging?

Logging enables us to monitor application flow and user interactions while identifying runtime errors and unexpected behaviors. It offers more structure and flexibility than print statements or interactive debuggers. Logs are particularly beneficial in production environments where direct debugging isn’t possible. Logs can also be saved for future analysis even after the application has stopped.

13.1.1 Architecture

We’re going to start logging the behaviors of our app in the inst/tidy-movies folder. The architecture of this application has been updated to include the two new input modules (review this app in Section 9.2.1):

%%{init: {'theme': 'neutral', 'themeVariables': { 'fontFamily': 'monospace', "fontSize":"16px"}}}%%
flowchart LR
        subgraph R["<strong>R/ folder</strong>"]
            subgraph launch["launch_app('ggp2')"]
                display_type["display_type()"]
            end
                mod_aes_input_ui["mod_aes_input_ui()"]
                mod_aes_input_server["mod_aes_input_server"]
                mod_var_input_server["mod_var_input_server()"]
                scatter_plot["scatter_plot()"]
        end

        subgraph tidy_movies["<strong>tidy-movies/ folder</strong>"]
            subgraph app["app.R file"]
                subgraph SubR["<strong>R/ folder</strong>"]
                devUI["devUI()"]
                dev_mod_vars_ui["dev_mod_vars_ui()"]
                dev_mod_scatter_ui["dev_mod_scatter_ui()"]
                devUI -->|"<em>Calls</em>"|dev_mod_vars_ui & dev_mod_scatter_ui
                devServer["devServer()"]
                dev_mod_scatter_server["dev_mod_scatter_server()"]
                devServer -->|"<em>Calls</em>"|dev_mod_scatter_server
                end
            end
            data[("tidy_movies.fst")]
            img[/"imdb.png"\]
        end
        

        launch ==> |"<strong><code>shinyAppDir()</code></strong>"|app
        mod_aes_input_ui -.->|"<em>Called from</em>"|devUI
        mod_var_input_server & mod_aes_input_server -.->|"<em>Called from</em>"|devServer
        scatter_plot --> |"<em>Called from</em>"|dev_mod_scatter_server
        
        
    %% R/
    style R fill:#e8f0f5,stroke:#333,stroke-width:1px,rx:3,ry:3
    %% standalone app function
    style launch fill:#F6F6F6,color:#000,stroke:#333,stroke-width:1px,rx:10,ry:10
    %% modules 
    style mod_var_input_server font-size:14px,color:#000,fill:#f5f5f5,stroke:#333,stroke-width:1px,rx:12,ry:12
    style mod_aes_input_ui font-size:14px,color:#000,fill:#f5f5f5,stroke:#333,stroke-width:1px,rx:12,ry:12
    style mod_aes_input_server font-size:14px,color:#000,fill:#f5f5f5,stroke:#333,stroke-width:1px,rx:12,ry:12
    %% utility functions
    style scatter_plot fill:#595959,color:#FFF,stroke:#333,stroke-width:1px,rx:25,ry:25
    style display_type fill:#595959,color:#FFF,stroke:#333,stroke-width:1px,rx:25,ry:25
    
    %% tidy-movies/ 
    style tidy_movies fill:#e8f0f5,stroke:#333,stroke-width:1px,rx:3,ry:3
    %% tidy-movies/R
    style SubR fill:#f7fafb,stroke:#333,stroke-width:1px,rx:3,ry:3
    %% tidy-movies/R/ files
    style devUI stroke:#333,stroke-width:1px,rx:6,ry:6
    style devServer stroke:#333,stroke-width:1px,rx:6,ry:6
    style dev_mod_scatter_server font-size:14px,color:#000,fill:#f5f5f5,stroke:#333,stroke-width:1px,rx:12,ry:12
    style dev_mod_scatter_ui font-size:14px,color:#000,fill:#f5f5f5,stroke:#333,stroke-width:1px,rx:12,ry:12
    style dev_mod_vars_ui font-size:14px,color:#000,fill:#f5f5f5,stroke:#333,stroke-width:1px,rx:12,ry:12
    %% files 
    style app fill:#f8f6e7,color:#000
    style data fill:#f8f6e7,color:#000
    style img fill:#f8f6e7,color:#000

Architecture of app functions in inst/tidy-movies/ folder

To launch the inst/tidy-movies app, load, document, and install sap and run:

Ctrl/Cmd + Shift + L
Ctrl/Cmd + Shift + D
Ctrl/Cmd + Shift + B

launch_app("ggp2")

Launching inst/tidy-movies app with launch_app()

Launching inst/tidy-movies app with launch_app()

The reactive values from the R/mod_var_input.R are printed to the Console from the previous chapter (review this in Section 12.3).

Validation and error handling ensures both expected and unexpected issues are managed effectively. Below I’ll briefly cover Shiny’s validate() function to check if input values or conditions are valid before executing server code and tryCatch() for handling unexpected runtime errors.

13.1.2 Validating inputs

validate() can be used to prevent unexpected errors by preventing the execution of subsequent code if the validation conditions fail.

  • Inside validate(), we can use need() to check if a condition is met
    • try() will catch any errors that occur if the inputs are NULL or missing.
      • If an error occurs, try() prevents the application from crashing and instead returns an error message:
validate(
  need(
    try(some code),
    "Error message"
  )
)

Below are example of validate(), try() and need() for the alpha and size inputs:

input$alpha

validate(
  need(
    try(input$alpha >= 0 & input$alpha <= 1),
    "Alpha must be between 0 and 1"
  )
)

Values and behaviors:

input$alpha Behavior
0.5 (valid) ✅ Passes validation
1.5 (invalid) ❌ Error: "Alpha must be between 0 and 1"
NULL ❌ Error: "Alpha must be between 0 and 1"
NA ❌ Error: "Alpha must be between 0 and 1"
"high" (string) ❌ Error: "Alpha must be between 0 and 1"

input$size

validate(
  need(
    try(input$size > 0),
    "Size must be positive"
  )
)

Values and behaviors:

input$size Behavior
3 (valid) ✅ Passes validation
-2 (invalid) ❌ Error: "Size must be positive"
NULL ❌ Error: "Size must be positive"
NA ❌ Error: "Size must be positive"
"large" (string) ❌ Error: "Size must be positive"

validate(), need() and try() can prevent unnecessary computations when an input is missing or incorrect, and they provide a user-friendly message instead of a cryptic error.

13.1.3 Handling errors

The base R tryCatch function can also be used to log unexpected errors gracefully. What does gracefully mean? In this case, it means we can decide what we want to do if a particular function fails. Below is an example of using it with reactive() and combining it message():

safe_reactive <- reactive({
    tryCatch({
        # Code that might throw an error
        
    }, error = function(e) {
        message(paste0("An error occurred:", e$message))
    })
})

tryCatch() will catch unpredictable errors (e.g., missing file, incorrect format) and prevent our entire Shiny app from stopping due to a single point of failure.

Combining Shiny’s validation functions with tryCatch() ensures both expected and unexpected issues are managed effectively, making our apps more resilient, user-friendly, and stable.

13.2 Base R logging

Custom logging functions can be written entirely using base R (i.e., without adding any dependencies to our app-package). Below is an example logging utility function I’ve added to the R/ folder to use in our app(s):

#' Log Application Behaviors
#'
#' A simple logging function for logging Shiny events and behaviors.
#' 
#' @param message log message
#' @param log_file name of log file (defaults to "app_log.txt")
#' @param save print or save log file
#'
#' @return A log message to the console and the `log_file`.
#'
#' @family **Utility Functions**
#' 
#' @examples
#' if (interactive()) {
#'   log_message("message")
#' }
#' 
#' @export
log_message <- function(message, log_file = "logs/app_log.txt", save = FALSE) {
  
  log_dir <- dirname(log_file)
  
  if (!dir.exists(log_dir)) {
    dir.create(log_dir, recursive = TRUE)
  }
  
  timestamp <- format(Sys.time(), "%Y-%m-%d %H:%M:%S")
  log_entry <- sprintf("[%s] %s", timestamp, message)
  
  if (save) {
    tryCatch({
        cat(log_entry, "\n", file = log_file, append = TRUE)
      },
      error = function(e) {
        warning(sprintf("Failed to write to log file '%s': %s", log_file, e$message)) 
      })
  }
  
  message(log_entry)
}
1
This function uses dirname() to dynamically extract the directory path from log_file.
2
dir.exists() and dir.create() ensure the folder exists (recursive = TRUE is for nested directories).
3
The sprintf() function is preferred over cat() or paste0() for clearer and faster string formatting.
4
The file-writing logic is wrapped in tryCatch() to gracefully handle errors (e.g., file permission issues), and we’ve added a warning() if writing to the log file fails.
5
We explicitly add the newline (\n) directly in the cat() function, ensuring the log entry is written properly even if message lacks a newline.
6
Finally, the message() is preferred here instead of print() for consistent output formatting.

In the inst/tidy-movies/ app, we could use log_message() and tryCatch() like so:

    all_data <- tryCatch({
      
      log_message(message = "Loading fst data",
        log_file = "_logs/ggp2_log.txt", save = TRUE)
      
      fst::read_fst("tidy_movies.fst")
      
    }, error = function(e) {
      
      log_message(message = sprintf("Error loading fst data: %s", e$message),
        log_file = "_logs/ggp2_log.txt", save = TRUE)
      
      stop("Data loading failed.")

    })
1
Saving to _logs because it’s easier to separate from other app folders.
2
Print error message from tryCatch()
3
Stop creation of reactive.

After loading and installing our package, the output from the log is saved in the log file (and printed to the Console) when our app stops running:

Logging data upload with log_message()

Logging data upload with log_message()

13.2.1 Logging events

We’ll continue to integrate log messages into the inst/tidy-movies app by inserting log_message() at critical points, such creating reactive expressions. For example, dev_mod_scatter_server() creates the graph_data() reactive based on the missing data checkbox user input:

graph_data <- reactive({
  if (input$missing) {
    graph_data <- tidyr::drop_na(data = all_data)
  } else {
    graph_data <- all_data
  }
}) |>
  bindEvent(input$missing)

We’ll add validate() and tryCatch() with a log_message() to log if 1) graph_data() contains all of the observations or the missing values have been removed, and 2) if the reactive was created successfully.

graph_data <- reactive({
  
  validate(
    need(try(is.logical(input$missing)), 
          "Missing must be logical")
  )
  
    tryCatch({
      if (input$missing) {
        
        log_message(message = "Removing missing values.",
                    log_file = "_logs/ggp2_log.txt", save = TRUE)
        graph_data <- tidyr::drop_na(data = all_data)
        
      } else {
        
        log_message(message = "Using all data.",
                    log_file = "_logs/ggp2_log.txt", save = TRUE)
        graph_data <- all_data
        
      }
      
      graph_data
      
    }, error = function(e) {
      
      log_message(message = sprintf("Error processing graph data: %s", e$message),
        log_file = "_logs/ggp2_log.txt", save = TRUE)
      NULL
      
    })
}) |> 
  bindEvent(input$missing)
1
Validation for missing checkbox input
2
Confirm missing values and create graph_data
3
Use all data and create graph_data
4
Print and log message is error occurs
5
Return null value for error

These logs will tell us the application loaded the .fst data and removed the missing values, but we should also check what happens when we change something, so we’ll adapt the code used to create our inputs() reactive with the log_message() function:

inputs <- reactive({

  tryCatch({
    plot_title <- tools::toTitleCase(aes_inputs()$plot_title)
    
    if (nchar(plot_title) > 0) {
      log_message(
        sprintf("Processing plot title: '%s'", plot_title), 
        log_file = "_logs/ggp2_log.txt")
    }
    
      input_list <- list(
        x = var_inputs()$x,
        y = var_inputs()$y,
        z = var_inputs()$z,
        alpha = aes_inputs()$alpha,
        size = aes_inputs()$size,
        plot_title = plot_title
      )
    
    log_message(
      sprintf("Inputs: %s", 
              paste(
                names(input_list), input_list, sep = " = ", collapse = ", ")
              ),
            log_file = "_logs/ggp2_log.txt", save = TRUE)
    
    input_list
  }, error = function(e) {
    
    log_message(
      sprintf("Error in processing inputs: %s", conditionMessage(e)),
      log_file = "_logs/ggp2_log.txt", save = TRUE)
    
    NULL
  })
})
1
Log the plot title.
2
Log the final input list.
3
Log the error if anything goes wrong.
4
Return NULL on error to prevent breaking downstream dependencies.

After loading and installing sap, we launch the inst/tidy-movies app again, but this time we un-check the remove missing checkbox and add a new plot title before stopping the application.

launch_app("ggp2")

Log messages from inputs()

Log messages from inputs()

To view the log file, we need to use system.file() (we’re launching the app from the installed location, not the version we’re developing in the inst/tidy-movies/ folder). I’ve added readLines() and writeLines() so it prints nicely to the Console:

system.file('tidy-movies', '_logs', 'ggp2_log.txt', 
            package = 'sap') |> 
            readLines() |> 
            writeLines()
[2025-01-29 11:34:40] Loading fst data 
[2025-01-29 11:34:40] Removing missing values. 
[2025-01-29 11:34:40] Inputs: x = year, y = budget, z = mpaa, alpha = 0.5, size = 2, plot_title =  
[2025-01-29 11:35:46] Loading fst data 
[2025-01-29 11:35:46] Removing missing values. 
[2025-01-29 11:35:46] Inputs: x = year, y = budget, z = mpaa, alpha = 0.5, size = 2, plot_title =  
[2025-01-29 11:35:52] Loading fst data 
[2025-01-29 11:35:52] Removing missing values. 
[2025-01-29 11:35:52] Inputs: x = year, y = budget, z = mpaa, alpha = 0.5, size = 2, plot_title =  
[2025-01-29 11:35:57] Inputs: x = year, y = budget, z = mpaa, alpha = 0.5, size = 2, plot_title = Title

In practice, we’d insert logging messages with log_message() and tryCatch() for application startup, loading data/connecting to databases, API calls, and when using Shiny’s internal validation/error handling functions. In the next section, we’re going to explore using add-on packages to implement logging in our app-package.

13.3 Logging with logger

Logging frameworks

The R ecosystem offers several libraries for logging.

The most popular options are:

This section will focus on the logger package because it is simple, easy to integrate with Shiny, and extensible.

install.packages("pak")
pak::pak("daroczig/logger")

Add logger to the package dependencies in the DESCRIPTION file and use the logger::fun() syntax to avoid adding @import or @importFrom roxygen tags.

usethis::use_package('logger')

13.3.1 Log levels

The logger package has a few configurations that can be very helpful for app-package development. We’ll start with a basic example using logger::log_info():

name <- "world"
logger::log_info('Hello, {name}')
INFO [2025-01-22 11:07:52] Hello, world

The output is a nicely formatted log message, and by default logger supports glue syntax. However, the following function (logger::log_debug()) doesn’t return a log message to the Console:

logger::log_debug('Hello, {name}')

This is because the logger package has a threshold configuration that controls the ‘verbosity’ of the logs printed to the Console. If we check the log_threshold(), we see it’s set to INFO:

logger::log_threshold()
Log level: INFO

If we reset the logger::log_threshold() to DEBUG, we will see the call in the Console.

logger::log_threshold('DEBUG')
logger::log_debug('Hello, {name}')
DEBUG [2025-01-22 11:08:36] Hello, world

We can set the log threshold dynamically to control the verbosity of logs:

logger::log_threshold('TRACE') # fine-grained, verbose logging for development
logger::log_threshold('DEBUG') # verbose logging for development
logger::log_threshold('WARN')  # only warnings and errors for production

While developing app-packages, I recommend broadly characterizing the logger log levels into the following categories:

Development

Descriptive messages for easier debugging

Level Details
TRACE Fine-grained tracking for debugging flows (e.g., reactive updates, function calls).
DEBUG Diagnostic information for inputs, intermediate states, and outputs.

Production

Lower verbosity levels

Level Details
INFO Session-level events and significant actions (e.g., app startup, data loading).
WARN Suspicious but non-fatal conditions (e.g., unusual input values or data sizes).
ERROR Handled errors with appropriate messaging and graceful recovery.
FATAL Critical failures leading to app crashes or irrecoverable states.

13.3.2 Storing log files

By default, logger logs are written to the console, but the logger::appender_file() function can direct log messages to a file (or to a database or external logging system).1

We also want to periodically archive old logs to prevent storage issues. Storing log messages as JSON objects is sometimes preferred because JSON files are structured, machine-readable, and can easily integrate with logging tools like Logstash, Kibana (ELK Stack) or other log management solutions.

13.3.3 Custom logger functions

We’ll write a custom logging function with logger to so our app logs are formatted and managed a consistent manner. Below is a logr_msg() utility function for inserting logger-style logs in our application.

logr_msg <- function(message, level = "INFO", log_file = NULL, json = FALSE) {
  
  logger::log_appender(appender = logger::appender_console)
  
  if (!is.null(log_file)) {
    if (json) {
      logger::log_layout(layout = logger::layout_json())
    } else {
      logger::log_appender(appender = logger::appender_tee(log_file))
    }
  }
  
  logger::log_formatter(formatter = logger::formatter_glue)
  
  switch(
    level,
    "FATAL" = logger::log_fatal("{message}"),
    "ERROR" = logger::log_error("{message}"),
    "WARN" = logger::log_warn("{message}"),
    "SUCCESS" = logger::log_success("{message}"),
    "INFO" = logger::log_info("{message}"),
    "DEBUG" = logger::log_debug("{message}"),
    "TRACE" = logger::log_trace("{message}"),
    logger::log_info("{message}")
  )
}
1
All logs print to console
2
Write logs to JSON if the json = TRUE
3
Default appender_tee for plain text logs
4
Set the default formatter
5
Handle all log levels
6
Default to INFO

log_appender controls where the log messages go. It specifies the “destination” for each log message, whether that’s the Console, a file, or both.

log_formatter is like a template for log messages–it determines how log each message is structured and displayed. We can control what information is included in each message (like the timestamp, log level, and the actual message), and how this information is formatted. Predefined formatters (like formatter_glue) uses glue syntax to create flexible and readable formats.

We’ll demonstrate logr_msg() with the mod_var_input_server() function, which returns the variable inputs from the UI. The message in logr_msg() is built with glue::glue() and includes the three reactive inputs from this module. We’re also appending the log output to a new log file (_logs/app_log.txt).

mod_var_input_server <- function(id) {
  moduleServer(id, function(input, output, session) {
    
    logr_msg("mod_var_input_server started",
      level = "TRACE", log_file = "_logs/app_log.txt")
    
    observe({
        logr_msg(
          glue::glue("Reactive inputs: 
                      x = {input$x}, y = {input$y}, z = {input$z}"),
          level = "DEBUG", log_file = "_logs/app_log.txt")
    }) |> 
      bindEvent(c(input$x, input$y, input$z))

    return(
      reactive({
        logr_msg(
          glue::glue("Reactive inputs returned: 
                      x = {input$x}, y = {input$y}, z = {input$z}"),
          level = "DEBUG", log_file = "_logs/app_log.txt")
        list(
          "x" = input$x,
          "y" = input$y,
          "z" = input$z
        )
      })
    )
  })
}
1
TRACE log for starting the module
2
DEBUG log for collecting inputs
3
DEBUG log for returning inputs

An advantage to using the logger package is that our log messages are automatically printed to the Console while the application is launched, although when we load and install sap and launch the inst/tidy-movies app, we don’t see any logs:

Ctrl/Cmd + Shift + L
Ctrl/Cmd + Shift + D
Ctrl/Cmd + Shift + B

launch_app("ggp2")

Initial messages from logr_msg()

Initial messages from logr_msg()

To view the log in our app, we need to set the log threshold:

logger::log_threshold('TRACE')
launch_app("ggp2")

The logs are now printed to the console and we can see the level, timestamp, and message:

Updates from logr_msg()

Updates from logr_msg()

13.4 Logging and debugging

Our primary application (i.e. the app launched with launch_app()) is currently displaying and error message:

Error message in launch_app()

Error message in launch_app()

Before adding our new custom logger function, we’ll review the architecture of this application and it’s modules.

13.4.1 Architecture

The diagram below illustrates the namespaces and module communication in our movies app. The ‘variables’ and ‘aesthetics’ input modules pass the user inputs into the ‘scatter display’ module namespace in the server and UI functions:

%%{init: {'theme': 'neutral', 'themeVariables': { 'fontFamily': 'monospace', "fontSize":"16px"}}}%%
flowchart TD
    subgraph Launch["<strong>launch_app()</strong>"]
        subgraph Server["<strong>movies_server()</strong>"]
            subgraph VarServerNS["<strong>Variable Namespace<strong>"]
                VarInpuServer["mod_var_input_server()"]
            end
            subgraph AesServerNS["<strong>Aesthetics Namespace<strong>"]
                AesInpuServer["mod_aes_input_server()"]
            end
            subgraph GraphServerNS["<strong>Graph Namespace<strong>"]
                DisplayServer["mod_scatter_display_server()"]
                PlotUtil["scatter_plot()"]
            end
        end
        subgraph UI["<strong>movies_ui()</strong>"]
            subgraph VarUINS["<strong>Variable Namespace<strong>"]
                VarInpuUI["mod_var_input_ui()"]
            end
            subgraph AesUINS["<strong>Aesthetics Namespace<strong>"]
                AesInpuUI["mod_aes_input_ui()"]
            end
            subgraph GraphUINS["<strong>Graph Namespace<strong>"]
                DisplayUI["mod_scatter_display_ui()"]
            end
        end

        VarInpuUI <==> VarInpuServer
        AesInpuUI <==> AesInpuServer
        DisplayServer <--> PlotUtil <==> DisplayUI
    end

    VarInpuServer <-.->|"Communicates<br><code>selected_vars</code><br>across modules"| DisplayServer
    AesInpuServer <-.->|"Communicates<br><code>selected_aes</code><br>across modules"| DisplayServer
    
    %% standalone app function 
    style Launch fill:#F6F6F6,color:#000,stroke:#333
    %% modules
    style VarInpuUI font-size:14px,color:#000,fill:#f5f5f5,stroke-width:2px,rx:3,ry:3
    style VarInpuServer font-size:14px,color:#000,fill:#f5f5f5,stroke-width:2px,rx:3,ry:3
    style AesInpuServer font-size:14px,color:#000,fill:#f5f5f5,stroke-width:2px,rx:3,ry:3
    style AesInpuUI font-size:14px,color:#000,fill:#f5f5f5,stroke-width:2px,rx:3,ry:3
    style DisplayServer font-size:12px,color:#000,fill:#f5f5f5,stroke-width:2px,rx:3,ry:3
    style DisplayUI font-size:14px,color:#000,fill:#f5f5f5,stroke-width:2px,rx:3,ry:3
    %% Utility Functions
    style PlotUtil fill:#595959,color:#FFF,stroke:#333,stroke-width:1px,rx:25,ry:25
    %% namespaces
    style VarServerNS fill:#f8f6e7,stroke-width:1px,rx:6,ry:6
    style VarUINS fill:#f8f6e7,stroke-width:1px,rx:6,ry:6
    style AesServerNS fill:#f8f6e7,stroke-width:1px,rx:6,ry:6
    style AesUINS fill:#f8f6e7,stroke-width:1px,rx:6,ry:6
    style GraphServerNS fill:#f8f6e7,stroke-width:1px,rx:6,ry:6
    style GraphUINS fill:#f8f6e7,stroke-width:1px,rx:6,ry:6
    %% UI and Server
    style Server fill:#e8f0f5,stroke-width:1px,rx:12,ry:12
    style UI fill:#e8f0f5,stroke-width:1px,rx:12,ry:12

Primary launch_app() app

The diagram above gives us an idea of the critical events we’ll want to log in the movies app. Below are examples of TRACE, INFO, WARN, ERROR, and FATAL log levels using logr_msg().

13.4.2 TRACE logs

  1. In movies_server(), a TRACE log message will signal the server function has executed:
  logr_msg(message = "Server function execution completed", 
           level = "TRACE", log_file = "_logs/app_log.txt")
  1. In mod_scatter_display_server(), a TRACE log message for initiating the scatterplot graph:
logr_msg("Preparing scatterplot in mod_scatter_display_server", 
          level = "TRACE", log_file = "_logs/app_log.txt")

13.4.3 INFO logs

  1. In launch_app(), an INFO log message prints the application being launched with the app argument:
  logr_msg(glue::glue("Launching app: {app}"), level = "INFO",
    log_file = "_logs/app_log.txt")
  1. In movies_ui(), an INFO log message prints the value of the bslib argument
  logr_msg(
    glue::glue("Launching UI with bslib = {bslib}"),
    level = "INFO", log_file = "_logs/app_log.txt")

13.4.4 WARN logs

  1. In mod_aes_input_server(), a WARN log message (with validate) prints input warnings:
      validate(
        need(try(input$alpha >= 0 & input$alpha <= 1), 
              "Alpha must be between 0 and 1")
      )
      if (input$alpha < 0 || input$alpha > 1) {
        logr_msg(message = "Alpha value out of range: {alpha}", 
        level = "WARN", log_file = "_logs/app_log.txt")
      }

13.4.5 ERROR logs

  1. In movies_ui(), logic and an ERROR log message monitors the format of the bslib argument:
if (!is.logical(bslib)) {
  logr_msg("Argument 'bslib' must be a logical value", 
    level = "ERROR", log_file = "_logs/app_log.txt")
    stop("Invalid argument: 'bslib' must be TRUE or FALSE.")
  }
  1. In mod_scatter_display_server(), an ERROR log message (with tryCatch()) monitors the rendered output:
  tryCatch({
    plot <- scatter_plot(
      # data --------------------
      df = movies,
      x_var = inputs()$x,
      y_var = inputs()$y,
      col_var = inputs()$z,
      alpha_var = inputs()$alpha,
      size_var = inputs()$size
    )
    plot +
      ggplot2::labs(
        title = inputs()$plot_title,
          x = stringr::str_replace_all(tools::toTitleCase(inputs()$x), "_", " "),
          y = stringr::str_replace_all(tools::toTitleCase(inputs()$y), "_", " ")
      ) +
      ggplot2::theme_minimal() +
      ggplot2::theme(legend.position = "bottom")
  }, error = function(e) {
  
  logr_msg(glue::glue("Failed to render scatterplot. Reason: {e$message}"), 
           level = "ERROR", log_file = "_logs/app_log.txt")
  
  })

13.4.6 FATAL logs

  1. In launch_app(), a FATAL log message (along with tryCatch() and stop()) monitors the application being launched:
  tryCatch({
    
    if (app == "bslib") {
      shinyApp(
        ui = movies_ui(bslib = TRUE),
        server = movies_server,
        options = options
      )
    } else if (app == "ggp2") {
      shinyAppDir(
        appDir = system.file("tidy-movies", package = "sap"),
        options = options
      )
    } else if (app == "quarto") {
      quarto::quarto_preview(
        system.file("quarto", "index.qmd", package = "sap"), 
        render = "all"
      )
    } else {
      app <- "movies"
      shinyApp(
        ui = movies_ui(...),
        server = movies_server,
        options = options
      )
    }
    
  }, error = function(e) {
    
    logr_msg(glue::glue("Application failed to launch. Reason: {e$message}"), 
             level = "FATAL",
             log_file = "_logs/app_log.txt")
    
    stop("Application launch failed. Check logs for details.")
    
  })

During development, I recommend setting the log threshold to TRACE or DEBUG after loading and installing sap:

Ctrl/Cmd + Shift + L
Ctrl/Cmd + Shift + D
Ctrl/Cmd + Shift + B

logger::log_threshold('TRACE')
launch_app()

Log error message in launch_app()

Log error message in launch_app()

The logs successfully capture all events up to and including the error message. While developing our application, we can run the app interactively and monitor the logs in the console. If the application has been deployed, we can search the log files using R (or the command line):

In R:

readLines("_logs/app_log.txt") |> 
  stringr::str_view("ERROR")
│ <ERROR> [2025-01-29 13:55:36] Failed to render scatterplot. 
  Reason: 'text' must be a character vector

At the command line:

cat _logs/app_log.txt | grep "ERROR"
ERROR [2025-01-29 13:55:36] Failed to render scatterplot. 
  Reason: 'text' must be a character vector

13.5 Package startup messages

Package startup messages help create a welcoming and professional impression when users load your app-package. These messages can also inform users of any specific requirements, dependencies, or potential conflicts. Package startup messages can also include the logging system (i.e., logger) being used, which can be helpful for debugging or monitoring during development or runtime.

13.5.1 .onAttach()

Write package startup messages in the .onAttach() function (stored in R/zzz.R).2 The example below includes a welcome message, the current Git branch, dependencies (imports, depends, and suggests), and the path where this package is loaded from.

.onAttach <- function(libname, pkgname) {
  
    branch <- if (isTRUE(system("git rev-parse --is-inside-work-tree", intern = TRUE) == "true")) {
    tryCatch({
      system("git rev-parse --abbrev-ref HEAD", intern = TRUE)
    }, error = function(e) "unknown")
  } else {
    "not a Git repository"
  }

  version <- utils::packageVersion(pkgname)

  description <- utils::packageDescription(pkgname)
  imports <- description$Imports
  suggests <- description$Suggests
  depends <- description$Depends

  parse_dependencies <- function(dep_string) {
    if (is.null(dep_string)) return("None")
    deps <- strsplit(dep_string, ",\\s*")[[1]]
    paste(deps, collapse = ", ")
  }

  imports <- parse_dependencies(imports)
  suggests <- parse_dependencies(suggests)
  depends <- parse_dependencies(depends)
  
  cli::cli_inform("{.strong Welcome to the {.pkg {pkgname}} package (version {version}) {cli::symbol$smiley}!}",
    class = "packageStartupMessage")
  
  cli::cli_inform("{.strong Current branch:}", class = "packageStartupMessage")
  cli::cli_inform("{.emph {cli::symbol$pointer} {branch}}", class = "packageStartupMessage")

  cli::cli_inform("{.strong Dependencies:}", class = "packageStartupMessage")
  cli::cli_inform("{.emph {cli::symbol$pointer} Imports: {imports}}", class = "packageStartupMessage")
  cli::cli_inform("{.emph {cli::symbol$pointer} Suggests: {suggests}}", class = "packageStartupMessage")
  cli::cli_inform("{.emph {cli::symbol$pointer} Depends: {depends}}", class = "packageStartupMessage")

  cli::cli_inform("{.strong Loaded from:}", class = "packageStartupMessage")
  cli::cli_inform("{.emph {cli::symbol$pointer} {libname}}", class = "packageStartupMessage")
}
1
Check if the current folder is a Git repo.
2
Capture the current branch if it’s a Git repo.
3
Package version.
4
Dependencies from DESCRIPTION.
5
Parse and format dependencies function.
6
Cleaned dependencies.
7
Welcome message.
8
Git branch.
9
Dependencies (header).
10
Dependencies (Imports from DESCRIPTION).
11
Dependencies (Suggests from DESCRIPTION).
12
Dependencies (Depends from DESCRIPTION).
13
Source of installed packages.
14
libname (a character string giving the library directory where the package defining the namespace was found.)

When we loading sap, we see the output from our startup message:

Package startup message in sap

Package startup message in sap

Including a startup message is a helpful tool, but it should be thoughtfully crafted to enhance the user experience without being intrusive. Avoid including a startup message if the app-package if the message doesn’t add meaningful value and becomes unnecessary “noise” for users.

Also, be sure to allow users to disable the message if possible (e.g., using suppressPackageStartupMessages()):

install.packages('pak')
pak::pak('mjfrigaard/sap')
suppressPackageStartupMessages(library(sap))
Initialize logging with .onLoad()

We can set up logger’s logging configuration in an onLoad function of the zzz.R file:

.onLoad <- function(libname, pkgname) {
    # configure logger log messages to console
    logger::log_appender(logger::appender_console)
    # configure logger log messages to file
    logger::log_appender(logger::appender_file('sap_apps.log'))
    # set default log level to DEBUG
    logger::log_threshold('DEBUG') 
}

This setup ensures that logging is ready as soon as your package is loaded.

Recap

The techniques discussed in this chapter will help you efficiently diagnose and resolve issues, making your Shiny app-package more robust and reliable.

Recap: Logging

Logging is an invaluable tool for debugging Shiny app-packages. By strategically placing log messages and configuring log levels, you can gain deep insights into your application’s behavior.

  • Use log levels to differentiate between logs.

  • Configure log settings with .onLoad() (stored in R/zzz.R)

  • Store package startup messages in onAttach() (stored in R/zzz.R)

  • Be selective with logging and avoid exposing or storing sensitive data.

By integrating structured logging, we can proactively detect issues, debug efficiently, and maintain application stability in production environments.

  1. Integrate with external logging systems (e.g., Syslog or Telegram) using custom appenders.↩︎

  2. Read more in the ‘Hooks for Namespace Events’ documentation.↩︎