Skip to content

Commit 8539d9c

Browse files
cdervcderv
committed
Add quarto_log function internally
This is first used in vignette engine to try debug the R_LIB issue
1 parent c617aff commit 8539d9c

File tree

5 files changed

+345
-7
lines changed

5 files changed

+345
-7
lines changed

‎R/quarto-args.R‎

Lines changed: 1 addition & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -5,10 +5,7 @@ cli_arg_profile <- function(profile, ...) {
55

66
is_quiet <- function(quiet) {
77
# in CI, follow debug mode
8-
if (
9-
identical(Sys.getenv("ACTIONS_RUNNER_DEBUG", ""), "true") ||
10-
identical(Sys.getenv("ACTIONS_STEP_DEBUG", ""), "true")
11-
) {
8+
if (in_ci_with_debug()) {
129
return(FALSE)
1310
}
1411
# these option takes precedence

‎R/r-logging.R‎

Lines changed: 121 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,121 @@
1+
in_debug_mode <- function() {
2+
in_ci_with_debug() || quarto_log_level("DEBUG") || is_quarto_r_debug()
3+
}
4+
5+
in_ci_with_debug <- function() {
6+
# check for GitHub Actions debug mode
7+
# https://docs.github.com/en/actions/learn-github-actions/environment-variables#default-environment-variables
8+
gha_debug <- Sys.getenv("ACTIONS_RUNNER_DEBUG", "") == "true" ||
9+
Sys.getenv("ACTIONS_STEP_DEBUG", "") == "true"
10+
return(gha_debug)
11+
}
12+
13+
# Return the current log level for Quarto
14+
# unless level is provided, in which case
15+
# it checks if the current log level matches the provided level.
16+
quarto_log_level <- function(level = NULL) {
17+
log_level <- Sys.getenv("QUARTO_LOG_LEVEL", NA)
18+
if (is.null(level)) {
19+
return(log_level)
20+
}
21+
return(identical(tolower(log_level), tolower(level)))
22+
}
23+
24+
#' @importFrom xfun env_option
25+
is_quarto_r_debug <- function() {
26+
# check option first, then environment variable
27+
# to allow setting in the R session
28+
# env var R_QUARTO_LOG_DEBUG
29+
isTRUE(as.logical(xfun::env_option('quarto.log.debug', FALSE)))
30+
}
31+
32+
# Get the configured log file path
33+
# Uses xfun::env_option to check for log file configuration
34+
# with option 'quarto.log.file' and env var 'R_QUARTO_LOG_FILE'
35+
#' @importFrom xfun env_option
36+
get_log_file <- function() {
37+
xfun::env_option('quarto.log.file', NULL)
38+
}
39+
40+
#' Log debug information to a configurable file
41+
#'
42+
#' This function logs messages to a file only when in debug mode.
43+
#' The log file can be configured via the `R_QUARTO_LOG_FILE` environment variable
44+
#' or the `quarto.log.file` option.
45+
#'
46+
#' @param ... Messages to log (will be concatenated)
47+
#' @param file Path to log file. If NULL, uses `get_log_file()` to determine the file.
48+
#' @param append Logical. Should the messages be appended to the file? Default TRUE.
49+
#' @param timestamp Logical. Should a timestamp be added? Default TRUE.
50+
#' @param prefix Character. Prefix to add before each log entry. Default "DEBUG: ".
51+
#'
52+
#' @return Invisibly returns TRUE if logging occurred, FALSE otherwise
53+
#'
54+
#' @examples
55+
#' \dontrun{
56+
#' # Set log file via environment variable
57+
#' Sys.setenv(R_QUARTO_LOG_FILE = "~/quarto-debug.log")
58+
#'
59+
#' # Or via option
60+
#' options(quarto.log.file = "~/quarto-debug.log")
61+
#'
62+
#' # Enable debug mode
63+
#' options(quarto.log.debug = TRUE)
64+
#'
65+
#' # Log some information
66+
#' quarto_log("Starting process")
67+
#' quarto_log("R_LIBS:", Sys.getenv("R_LIBS"))
68+
#' quarto_log(".libPaths():", paste0(.libPaths(), collapse = ":"))
69+
#' }
70+
quarto_log <- function(
71+
...,
72+
file = NULL,
73+
append = TRUE,
74+
timestamp = TRUE,
75+
prefix = "DEBUG: "
76+
) {
77+
if (!in_debug_mode()) {
78+
return(invisible(FALSE))
79+
}
80+
81+
if (is.null(file)) {
82+
file <- get_log_file()
83+
}
84+
85+
if (is.null(file)) {
86+
# No log file configured, skip logging
87+
return(invisible(FALSE))
88+
}
89+
90+
# Construct the message
91+
msg_parts <- list(...)
92+
msg <- paste(msg_parts, collapse = "")
93+
94+
# Add prefix if provided
95+
if (!is.null(prefix) && nchar(prefix) > 0) {
96+
msg <- paste0(prefix, msg)
97+
}
98+
99+
# Add timestamp if requested
100+
if (timestamp) {
101+
ts <- format(Sys.time(), "[%Y-%m-%d %H:%M:%S] ")
102+
msg <- paste0(ts, msg)
103+
}
104+
105+
# Ensure message ends with newline
106+
if (!grepl("\n$", msg)) {
107+
msg <- paste0(msg, "\n")
108+
}
109+
110+
# Write to file
111+
tryCatch(
112+
{
113+
cat(msg, file = file, append = append)
114+
return(invisible(TRUE))
115+
},
116+
error = function(e) {
117+
# If we can't write to the file, fail silently in debug logging
118+
return(invisible(FALSE))
119+
}
120+
)
121+
}

‎R/utils-vignettes.R‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -34,9 +34,10 @@ vweave_quarto <- function(format) {
3434
return(vweave_empty(file))
3535
}
3636

37-
cat("R_LIBS:", Sys.getenv("R_LIBS"), "\n", sep = "", file = "~/desktop/log.txt", append = TRUE)
38-
cat(".libPaths(): ", paste0(.libPaths(), collapse = ":"), "\n", sep = "", file = "~/desktop/log.txt", append = TRUE)
39-
cat("Packages:", paste0(dir(.libPaths()[1]), collapse = ","), "\n", sep = "", file = "~/desktop/log.txt", append = TRUE)
37+
# Log debug information using the new configurable logging function
38+
quarto_log("R_LIBS: ", Sys.getenv("R_LIBS"))
39+
quarto_log(".libPaths(): ", paste0(.libPaths(), collapse = ":"))
40+
quarto_log("Packages: ", paste0(dir(.libPaths()[1]), collapse = ","))
4041

4142
quarto_render(file, ..., output_format = format, metadata = meta)
4243
}

‎man/quarto_log_level.Rd‎

Lines changed: 15 additions & 0 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎tests/testthat/test-r-logging.R‎

Lines changed: 204 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,204 @@
1+
test_that("options quarto.log.debug and env var R_QUARTO_LOG_DEBUG", {
2+
# clean state
3+
withr::local_options(quarto.log.debug = NULL)
4+
withr::local_envvar(R_QUARTO_LOG_DEBUG = NA)
5+
expect_false(is_quarto_r_debug())
6+
withr::with_envvar(list(R_QUARTO_LOG_DEBUG = TRUE), {
7+
expect_true(is_quarto_r_debug())
8+
# option takes precedence over env var
9+
withr::with_options(list(quarto.log.debug = FALSE), {
10+
expect_false(is_quarto_r_debug())
11+
})
12+
})
13+
withr::with_options(list(quarto.log.debug = TRUE), {
14+
expect_true(is_quarto_r_debug())
15+
})
16+
withr::with_envvar(list(R_QUARTO_LOG_DEBUG = FALSE), {
17+
expect_false(is_quarto_r_debug())
18+
# option takes precedence over env var
19+
withr::with_options(list(quarto.log.debug = TRUE), {
20+
expect_true(is_quarto_r_debug())
21+
})
22+
})
23+
})
24+
25+
test_that("quarto_log_level respects Quarto env var", {
26+
withr::local_envvar(QUARTO_LOG_LEVEL = NA)
27+
expect_true(is.na(quarto_log_level()))
28+
expect_false(quarto_log_level("DEBUG"))
29+
withr::with_envvar(list(QUARTO_LOG_LEVEL = "DEBUG"), {
30+
expect_true(quarto_log_level("DEBUG"))
31+
expect_false(quarto_log_level("INFO"))
32+
expect_false(quarto_log_level("ERROR"))
33+
})
34+
withr::with_envvar(list(QUARTO_LOG_LEVEL = "INFO"), {
35+
expect_false(quarto_log_level("DEBUG"))
36+
expect_true(quarto_log_level("INFO"))
37+
expect_false(quarto_log_level("ERROR"))
38+
})
39+
withr::with_envvar(list(QUARTO_LOG_LEVEL = "ERROR"), {
40+
expect_false(quarto_log_level("DEBUG"))
41+
expect_false(quarto_log_level("INFO"))
42+
expect_true(quarto_log_level("ERROR"))
43+
})
44+
})
45+
46+
test_that("in_debug_mode respects GHA CI env var", {
47+
withr::local_envvar(ACTIONS_RUNNER_DEBUG = NA, ACTIONS_STEP_DEBUG = NA)
48+
expect_false(in_debug_mode())
49+
50+
withr::with_envvar(list(ACTIONS_RUNNER_DEBUG = "true"), {
51+
expect_true(in_debug_mode())
52+
})
53+
54+
withr::with_envvar(list(ACTIONS_STEP_DEBUG = "true"), {
55+
expect_true(in_debug_mode())
56+
})
57+
58+
withr::with_envvar(
59+
list(ACTIONS_RUNNER_DEBUG = "false", ACTIONS_STEP_DEBUG = "false"),
60+
{
61+
expect_false(in_debug_mode())
62+
}
63+
)
64+
})
65+
66+
test_that("in_debug mode respects quarto_log_level", {
67+
# clean state
68+
withr::local_envvar(ACTIONS_RUNNER_DEBUG = NA, ACTIONS_STEP_DEBUG = NA)
69+
withr::local_envvar(QUARTO_LOG_LEVEL = NA)
70+
expect_false(in_debug_mode())
71+
72+
withr::with_envvar(list(QUARTO_LOG_LEVEL = "DEBUG"), {
73+
expect_true(in_debug_mode())
74+
})
75+
76+
withr::with_envvar(list(QUARTO_LOG_LEVEL = "INFO"), {
77+
expect_false(in_debug_mode())
78+
})
79+
80+
withr::with_envvar(list(QUARTO_LOG_LEVEL = "ERROR"), {
81+
expect_false(in_debug_mode())
82+
})
83+
})
84+
85+
test_that("in_debug_mode respects R_QUARTO_LOG_DEBUG and quarto.log.debug", {
86+
# clean state
87+
withr::local_envvar(ACTIONS_RUNNER_DEBUG = NA, ACTIONS_STEP_DEBUG = NA)
88+
withr::local_envvar(QUARTO_LOG_LEVEL = NA)
89+
withr::local_envvar(R_QUARTO_LOG_DEBUG = NA)
90+
withr::local_options(quarto.log.debug = NULL)
91+
expect_false(in_debug_mode())
92+
93+
withr::with_envvar(list(R_QUARTO_LOG_DEBUG = TRUE), {
94+
expect_true(in_debug_mode())
95+
withr::with_options(list(quarto.log.debug = FALSE), {
96+
expect_false(in_debug_mode())
97+
})
98+
withr::with_options(list(quarto.log.debug = TRUE), {
99+
expect_true(in_debug_mode())
100+
})
101+
})
102+
103+
withr::with_envvar(list(R_QUARTO_LOG_DEBUG = FALSE), {
104+
expect_false(in_debug_mode())
105+
withr::with_options(list(quarto.log.debug = TRUE), {
106+
expect_true(in_debug_mode())
107+
})
108+
withr::with_options(list(quarto.log.debug = FALSE), {
109+
expect_false(in_debug_mode())
110+
})
111+
})
112+
})
113+
114+
test_that("quarto_log only logs when in debug mode", {
115+
temp_file <- tempfile(fileext = ".log")
116+
on.exit(unlink(temp_file))
117+
118+
# Test with debug mode off
119+
withr::local_envvar(ACTIONS_RUNNER_DEBUG = NA, ACTIONS_STEP_DEBUG = NA)
120+
withr::local_envvar(QUARTO_LOG_LEVEL = NA)
121+
withr::local_envvar(R_QUARTO_LOG_DEBUG = NA)
122+
withr::local_options(quarto.log.debug = NULL)
123+
124+
result <- quarto_log("test message", file = temp_file)
125+
expect_false(result)
126+
expect_false(file.exists(temp_file))
127+
128+
# Test with debug mode on
129+
withr::with_options(list(quarto.log.debug = TRUE), {
130+
result <- quarto_log("test message", file = temp_file)
131+
expect_true(result)
132+
expect_true(file.exists(temp_file))
133+
134+
content <- readLines(temp_file)
135+
expect_true(grepl("DEBUG: test message", content[1]))
136+
expect_true(grepl(
137+
"\\[\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}\\]",
138+
content[1]
139+
))
140+
})
141+
})
142+
143+
test_that("quarto_log respects log file configuration", {
144+
temp_file <- tempfile(fileext = ".log")
145+
on.exit(unlink(temp_file))
146+
147+
# Enable debug mode
148+
withr::local_options(quarto.log.debug = TRUE)
149+
150+
# Test with file parameter
151+
result <- quarto_log("direct file", file = temp_file)
152+
expect_true(result)
153+
expect_true(file.exists(temp_file))
154+
155+
# Test with option
156+
unlink(temp_file)
157+
withr::with_options(list(quarto.log.file = temp_file), {
158+
result <- quarto_log("via option")
159+
expect_true(result)
160+
expect_true(file.exists(temp_file))
161+
})
162+
163+
# Test with environment variable (R_QUARTO_LOG_FILE)
164+
unlink(temp_file)
165+
withr::with_envvar(list(R_QUARTO_LOG_FILE = temp_file), {
166+
result <- quarto_log("via env var")
167+
expect_true(result)
168+
expect_true(file.exists(temp_file))
169+
})
170+
171+
# Test with no file configured
172+
result <- quarto_log("no file configured")
173+
expect_false(result)
174+
})
175+
176+
test_that("quarto_log handles custom formatting", {
177+
temp_file <- tempfile(fileext = ".log")
178+
on.exit(unlink(temp_file))
179+
180+
withr::local_options(quarto.log.debug = TRUE)
181+
182+
# Test without timestamp
183+
quarto_log("no timestamp", file = temp_file, timestamp = FALSE)
184+
content <- readLines(temp_file)
185+
expect_equal(content[1], "DEBUG: no timestamp")
186+
187+
# Test without prefix
188+
quarto_log("no prefix", file = temp_file, prefix = "", append = FALSE)
189+
content <- readLines(temp_file)
190+
expect_true(grepl(
191+
"^\\[\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}\\] no prefix$",
192+
content[1]
193+
))
194+
195+
# Test custom prefix
196+
quarto_log(
197+
"custom prefix",
198+
file = temp_file,
199+
prefix = "CUSTOM: ",
200+
append = FALSE
201+
)
202+
content <- readLines(temp_file)
203+
expect_true(grepl("CUSTOM: custom prefix", content[1]))
204+
})

0 commit comments

Comments
 (0)