From 3aa0841666c5d9186f84fb1ca2787ec15b68f68d Mon Sep 17 00:00:00 2001 From: Brandon Moretz Date: Sat, 12 Mar 2022 18:06:43 -0500 Subject: [PATCH] ground-up rewrite of the dynamic logging dispatch see release notes for more detail about the changes --- DESCRIPTION | 2 +- NAMESPACE | 1 + NEWS.md | 18 ++- R/config.R | 72 ++++++++- R/dispatch.R | 222 ++++++++++++-------------- R/format.R | 12 +- R/z-pkg-events.r | 6 +- man/LogDispatch.Rd | 82 ++-------- man/active.Rd | 17 ++ man/apply_active_settings.Rd | 27 ++++ man/config_specification.Rd | 3 + man/create_log_levels.Rd | 28 ++++ man/display_log_levels.Rd | 3 + man/ensure_logger.Rd | 3 + man/get_active_settings.Rd | 23 +++ man/load_log_layouts.Rd | 3 + man/value.fmt_log_level.Rd | 4 +- man/value.fmt_log_msg.Rd | 4 +- man/wipe_logger.Rd | 3 + tests/testthat/helper-objects.R | 27 +++- tests/testthat/test-cls-association.R | 10 +- tests/testthat/test-config.R | 91 ++++++++--- tests/testthat/test-dispatch.R | 56 +++---- tests/testthat/test-layout.R | 37 ++--- tests/testthat/test-level.R | 17 -- vignettes/Configuration.Rmd | 4 - vignettes/Formats.Rmd | 3 +- 27 files changed, 452 insertions(+), 326 deletions(-) create mode 100644 man/active.Rd create mode 100644 man/apply_active_settings.Rd create mode 100644 man/create_log_levels.Rd create mode 100644 man/get_active_settings.Rd diff --git a/DESCRIPTION b/DESCRIPTION index 9562a62..9806df0 100644 --- a/DESCRIPTION +++ b/DESCRIPTION @@ -1,7 +1,7 @@ Package: dyn.log Type: Package Title: Dynamic Logging for R Inspired by Configuration Driven Development -Version: 0.3.3 +Version: 0.4.0 Authors@R: c(person(given = "Brandon", family = "Moretz", diff --git a/NAMESPACE b/NAMESPACE index 0432187..b87281d 100644 --- a/NAMESPACE +++ b/NAMESPACE @@ -21,6 +21,7 @@ export(display_log_levels) export(ensure_logger) export(evaluate_layout) export(exec_context) +export(get_active_settings) export(get_configurations) export(init_logger) export(level_description) diff --git a/NEWS.md b/NEWS.md index 84e3191..aeb1d17 100644 --- a/NEWS.md +++ b/NEWS.md @@ -1,5 +1,21 @@ # Release Summaries +# dyn.log 0.4.0 + +## What's Changed + +* New Features + + Ground-up rewrite of the dynamic log dispatch mechanics, to make them: + + Simpler. There were areas of the old implementation that were incredibly hard to follow (log levels and log messages, in particular). + + Consistent. Every format object that needs contextual information now gets it injected via the context list in the dispatch function. + + Cleaner. Now leverages even more awesomeness from [rlang](https://github.com/r-lib/rlang), specifically 'rlang::new_function' to dynamically create the log dispatch routines & 'rlang::pairlist2' to handle completely dynamic & non-defaulted parameters (msg). + + Testable. The new mechanics are much more unit testable, and once the code is cleaned up more (and simplified further), will focus on this area. + +* Enhancements + + updated the README.md to be more reflective of the overall goal of the package. + + streamlined the configuration (in init_logger) to have clear separation of concerns. + + added a 'default' logger method that is based on the attached level with the highest severity, so in areas where you always want the lowest possible information logged (even if configurations change) then you can just use 'Logger$default.' Useful for packages that might be attached by multiple downstream packages with different level definitions. + # dyn.log 0.3.3 ## What's Changed @@ -17,7 +33,7 @@ * Other + vscode support - + moved the development configuration that supports vscode into a separate branch and cleaned up all the additional dependencies. + + moved the development configuration that supports vscode into a separate branch and cleaned up all the additional dependencies. # dyn.log 0.3.2 diff --git a/R/config.R b/R/config.R index 4f7de0d..9011aa7 100644 --- a/R/config.R +++ b/R/config.R @@ -55,13 +55,18 @@ init_logger <- function(file_path = NULL) { config <- yaml::read_yaml(config_file, eval.expr = TRUE) config_name <- tools::file_path_sans_ext(basename(config_file)) + log_levels <- create_log_levels(config$levels) + apply_active_settings(config$settings) + ensure_logger(config$variable) if (!identical(active$config, config_name)) { logger <- LogDispatch$new() - logger$set_settings(config$settings) - logger$attach_log_levels(config$levels) + sapply(log_levels, function(level) { + logger$attach_log_level(level) + }) + logger$default("dyn.log loaded '{config_name}' configuration successfully.") active$config <- config_name @@ -127,6 +132,62 @@ wipe_logger <- function() { } } +#' @title Apply Active Logger Settings +#' +#' @description +#' Parses and loads the settings specified +#' in the logger configuration and ensures +#' they are active in the environment. +#' +#' @param settings defined in the configuration +#' +#' @family Configuration +apply_active_settings = function(settings) { + + threshold_level <- log_levels(settings$threshold) + + active$threshold <- list() + active$threshold$name <- level_name(threshold_level) + active$threshold$severity <- level_severity(threshold_level) + + active$callstack <- list() + active$callstack$max <- settings$callstack$max + active$callstack$start <- settings$callstack$start + active$callstack$stop <- settings$callstack$stop +} + +#' @title Active Logger Settings +#' +#' @description +#' Gets the active global settings +#' for the logger. +#' +#' @family Configuration +#' @export +get_active_settings = function() { + as.list(active) +} + +#' @title Attach Log Levels +#' +#' @description +#' Parses and loads the levels specified in the +#' logging configuration and registers them with the +#' dispatcher via the \code{log_levels} active +#' binding. +#' +#' @param definitions defined in the configuration +#' @family Configuration +create_log_levels = function(definitions) { + sapply(definitions, function(level) { + new_log_level(name = level$name, + description = level$description, + severity = as.integer(level$severity), + log_style = level$log_style, + msg_style = level$msg_style) + }) +} + #' @title Load Log Layouts #' #' @description @@ -142,7 +203,7 @@ wipe_logger <- function() { #' @returns None. load_log_layouts <- function(layouts) { - invisible(sapply(layouts, function(layout) { + sapply(layouts, function(layout) { if (identical(class(layout$format), "character")) { parsed <- stringr::str_split(layout$formats, @@ -162,7 +223,9 @@ load_log_layouts <- function(layouts) { new_line = layout$new_line, association = layout$association ) - })) + }) + + invisible() } #' @title Display Log Levels @@ -177,6 +240,7 @@ load_log_layouts <- function(layouts) { #' #' @export display_log_levels <- function() { + sapply(log_levels(), function(level) { info <- level_info(level) logger <- LogDispatch$new() diff --git a/R/dispatch.R b/R/dispatch.R index 6e9c3a4..9a3dbd6 100644 --- a/R/dispatch.R +++ b/R/dispatch.R @@ -31,140 +31,39 @@ LogDispatch <- R6::R6Class( #nolint initialize = function() { if (is.null(private$public_bind_env)) { + private$default_severitiy <- 0 private$create_singleton(LogDispatch) } else { self <- private$instance - private$copy_env("public_bind_env", - private$public_bind_env) - - private$copy_env("private_bind_env", - private$private_bind_env) + private$set_bindings() } invisible(self) }, #' @description - #' Parses and loads the levels specified in the - #' logging configuration and registers them with the - #' dispatcher via the \code{log_levels} active - #' binding. - #' - #' @param levels defined in the configuration - #' @family Logging - attach_log_levels = function(levels) { - - sapply(levels, function(level) { - new_level <- new_log_level(name = level$name, - description = level$description, - severity = as.integer(level$severity), - log_style = level$log_style, - msg_style = level$msg_style) - - self$add_log_level(new_level) - }) - - # used internally to log information - min_severity <- get_minimum_severity() - self[["default"]] <- self[[min_severity]] - - invisible() - }, - - #' @description - #' Adds dynamic function as a short-cut to - #' log a message with a configured level. + #' Attaches a S3 \code{log_level} object to the log + #' dispatcher by creating a new function wrapping the + #' specified log level, and binding and instance + #' of the dispatcher quote block with + #' the context of the log level. #' - #' @param level log level - #' - #' @return reference to self to support chaining. - add_log_level = function(level) { - # nocov start - name <- tolower(level_name(level)) - - self[[name]] <- function(msg, - parent = parent.frame(), - layout = "default") { - - current <- level_severity(level) - threshold <- level_severity(log_levels(private$settings$threshold)) - - if (current > threshold) return() - - caller_env <- rlang::caller_env() - parent_env <- parent.env(caller_env) + #' @param log_level log level to attach + attach_log_level = function(log_level) { - has_calling_class <- ifelse(is.null(parent_env$self), FALSE, TRUE) - calling_class <- NA - log_msg <- glue::glue(msg, .envir = parent) + fn_name <- tolower(level_name(log_level)) + dispatch <- private$create_level_dispatch(log_level) - log_layout <- log_layouts(layout) + self[[fn_name]] <- dispatch - if (has_calling_class) { - calling_class <- parent_env$self - - # match class name(s) against registered - # log layouts, to find the "best" class - # association given its hierarchy. - cls_name <- class(calling_class) - registered <- names(log_layouts()) - layout_idx <- max(c(0L, match(cls_name, registered)), na.rm = TRUE) - - if (layout_idx > 0) { - log_layout <- log_layouts(registered[layout_idx]) - } - } - - if (is.null(layout)) { - stop("cannot log without an associated layout.") - } - - detail <- log_layout_detail(log_layout) - - context <- list() - - if (has_calling_class && any(!is.na(match(detail$types, "fmt_cls_field")))) { - context[["fmt_cls_field"]] <- class_scope(calling_class) - } - - if (any(!is.na(match(detail$types, "fmt_metric")))) { - context[["fmt_metric"]] <- sys_context() - } - - if (any(!is.na(match(detail$types, "fmt_exec_scope")))) { - - context[["fmt_exec_scope"]] <- exec_context( - max_calls = private$settings$callstack$max, - call_subset = c(private$settings$callstack$start, - private$settings$callstack$stop)) - } - - evaluated <- evaluate_layout(detail, context) - - cat(glue::glue(evaluated), - fill = TRUE, - file = stdout()) + lvl_sev <- level_severity(log_level) + if (lvl_sev > private$default_severitiy) { + self[["default"]] <- dispatch + private$default_severitiy <- lvl_sev } invisible(self) - # nocov end - }, - - #' @description - #' Public wrapper around logger settings. - #' @return logger settings. - get_settings = function() { - private$settings - }, - - #' @description - #' Public wrapper around updating settings. - #' @param settings Logger settings. - #' @return None. - set_settings = function(settings) { - private$settings <- settings - invisible() } ), @@ -172,7 +71,7 @@ LogDispatch <- R6::R6Class( #nolint private = list( - settings = NULL, + default_severitiy = NULL, # overrides from base R6 public_bind_env = NULL, @@ -184,9 +83,9 @@ LogDispatch <- R6::R6Class( #nolint private$private_bind_env <- base::dynGet("private_bind_env") obj$set("private", - "public_bind_env", - private$public_bind_env, - overwrite = TRUE) + "public_bind_env", + private$public_bind_env, + overwrite = TRUE) obj$set("private", "private_bind_env", @@ -217,6 +116,87 @@ LogDispatch <- R6::R6Class( #nolint } invisible() + }, + + create_level_dispatch = function(level) { + rlang::new_function( + args = rlang::pairlist2(msg = , + level = level, + layout = "default"), + body = dispatcher, + env = rlang::caller_env() + ) } ) ) + +dispatcher <- quote({ + + if (is.null(level)) return() + + if (level_severity(level) > active$threshold$severity) return() + + caller_env <- rlang::caller_env() + parent_env <- parent.env(caller_env) + + has_calling_class <- ifelse(is.null(parent_env$self), FALSE, TRUE) + calling_class <- NA + + log_msg <- glue::glue(msg, .envir = caller_env) + log_layout <- log_layouts(layout) + + if (has_calling_class) { + calling_class <- parent_env$self + + # match class name(s) against registered + # log layouts, to find the "best" class + # association given its hierarchy. + cls_name <- class(calling_class) + registered <- names(log_layouts()) + layout_idx <- max(c(0L, match(cls_name, registered)), na.rm = TRUE) + + if (layout_idx > 0) { + log_layout <- log_layouts(registered[layout_idx]) + } + } + + if (is.null(layout)) { + stop("cannot log without an associated layout.") + } + + detail <- log_layout_detail(log_layout) + + context <- list() + + context[["fmt_log_level"]] <- list( + name = level_name(level), + level = level + ) + + context[["fmt_log_msg"]] <- list( + msg = log_msg, + level = level + ) + + if (has_calling_class && any(!is.na(match(detail$types, "fmt_cls_field")))) { + context[["fmt_cls_field"]] <- class_scope(calling_class) + } + + if (any(!is.na(match(detail$types, "fmt_metric")))) { + context[["fmt_metric"]] <- sys_context() + } + + if (any(!is.na(match(detail$types, "fmt_exec_scope")))) { + + context[["fmt_exec_scope"]] <- exec_context( + max_calls = active$callstack$max, + call_subset = c(active$callstack$start, + active$callstack$stop)) + } + + evaluated <- evaluate_layout(detail, context) + + cat(evaluated, + fill = TRUE, + file = stdout()) +}) diff --git a/R/format.R b/R/format.R index bd8615a..aa56476 100644 --- a/R/format.R +++ b/R/format.R @@ -30,7 +30,6 @@ new_fmt_log_level <- function() { structure( list(), style = crayon::black, - value = glue::as_glue("{format(level)}"), class = c("fmt_log_level", "fmt_layout") ) } @@ -42,12 +41,13 @@ new_fmt_log_level <- function() { #' log level information. #' #' @param obj object to extract value from. +#' @param lvl_context context to evaluate log level. #' @param ... further arguments passed to or from other methods. #' #' @return object's value #' @export -value.fmt_log_level <- function(obj, ...) { # nolint (generic) - attr(obj, "value") +value.fmt_log_level <- function(obj, lvl_context, ...) { # nolint (generic) + format(lvl_context$level, message = lvl_context$name) } #' @title @@ -63,7 +63,6 @@ new_fmt_log_msg <- function() { structure( list(), style = crayon::black, - value = glue::as_glue("{format(level, message = {log_msg})}"), class = c("fmt_log_msg", "fmt_layout") ) } @@ -75,12 +74,13 @@ new_fmt_log_msg <- function() { #' log format message. #' #' @param obj object to extract value from. +#' @param msg_context context to evaluate log message. #' @param ... further arguments passed to or from other methods. #' #' @return object's value #' @export -value.fmt_log_msg <- function(obj, ...) { # nolint (generic) - attr(obj, "value") +value.fmt_log_msg <- function(obj, msg_context, ...) { # nolint (generic) + format(msg_context$level, message = msg_context$msg) } #' @title Formatted Metric diff --git a/R/z-pkg-events.r b/R/z-pkg-events.r index 6fdf840..9418753 100644 --- a/R/z-pkg-events.r +++ b/R/z-pkg-events.r @@ -1,4 +1,8 @@ -# active logger configuration +#' @title Active Settings +#' +#' @description +#' Package environment variable to hold +#' global level settings. active <- new.env(parent = emptyenv()) #' @title Load Handler diff --git a/man/LogDispatch.Rd b/man/LogDispatch.Rd index ee9c74c..5551ee7 100644 --- a/man/LogDispatch.Rd +++ b/man/LogDispatch.Rd @@ -15,10 +15,6 @@ layouts (render formats), which are used by the \code{LogDispatcher} to render highly-customizable and detailed log messages. } \seealso{ -Other Logging: -\code{\link{get_configurations}()}, -\code{\link{init_logger}()} - Other Logging: \code{\link{get_configurations}()}, \code{\link{init_logger}()} @@ -28,10 +24,7 @@ Other Logging: \subsection{Public methods}{ \itemize{ \item \href{#method-new}{\code{LogDispatch$new()}} -\item \href{#method-attach_log_levels}{\code{LogDispatch$attach_log_levels()}} -\item \href{#method-add_log_level}{\code{LogDispatch$add_log_level()}} -\item \href{#method-get_settings}{\code{LogDispatch$get_settings()}} -\item \href{#method-set_settings}{\code{LogDispatch$set_settings()}} +\item \href{#method-attach_log_level}{\code{LogDispatch$attach_log_level()}} } } \if{html}{\out{
}} @@ -48,77 +41,24 @@ A new \code{LogLayout} object. } } \if{html}{\out{
}} -\if{html}{\out{}} -\if{latex}{\out{\hypertarget{method-attach_log_levels}{}}} -\subsection{Method \code{attach_log_levels()}}{ -Parses and loads the levels specified in the -logging configuration and registers them with the -dispatcher via the \code{log_levels} active -binding. +\if{html}{\out{}} +\if{latex}{\out{\hypertarget{method-attach_log_level}{}}} +\subsection{Method \code{attach_log_level()}}{ +Attaches a S3 \code{log_level} object to the log +dispatcher by creating a new function wrapping the +specified log level, and binding and instance +of the dispatcher quote block with +the context of the log level. \subsection{Usage}{ -\if{html}{\out{
}}\preformatted{LogDispatch$attach_log_levels(levels)}\if{html}{\out{
}} +\if{html}{\out{
}}\preformatted{LogDispatch$attach_log_level(log_level)}\if{html}{\out{
}} } \subsection{Arguments}{ \if{html}{\out{
}} \describe{ -\item{\code{levels}}{defined in the configuration} +\item{\code{log_level}}{log level to attach} } \if{html}{\out{
}} } } -\if{html}{\out{
}} -\if{html}{\out{}} -\if{latex}{\out{\hypertarget{method-add_log_level}{}}} -\subsection{Method \code{add_log_level()}}{ -Adds dynamic function as a short-cut to -log a message with a configured level. -\subsection{Usage}{ -\if{html}{\out{
}}\preformatted{LogDispatch$add_log_level(level)}\if{html}{\out{
}} -} - -\subsection{Arguments}{ -\if{html}{\out{
}} -\describe{ -\item{\code{level}}{log level} -} -\if{html}{\out{
}} -} -\subsection{Returns}{ -reference to self to support chaining. -} -} -\if{html}{\out{
}} -\if{html}{\out{}} -\if{latex}{\out{\hypertarget{method-get_settings}{}}} -\subsection{Method \code{get_settings()}}{ -Public wrapper around logger settings. -\subsection{Usage}{ -\if{html}{\out{
}}\preformatted{LogDispatch$get_settings()}\if{html}{\out{
}} -} - -\subsection{Returns}{ -logger settings. -} -} -\if{html}{\out{
}} -\if{html}{\out{}} -\if{latex}{\out{\hypertarget{method-set_settings}{}}} -\subsection{Method \code{set_settings()}}{ -Public wrapper around updating settings. -\subsection{Usage}{ -\if{html}{\out{
}}\preformatted{LogDispatch$set_settings(settings)}\if{html}{\out{
}} -} - -\subsection{Arguments}{ -\if{html}{\out{
}} -\describe{ -\item{\code{settings}}{Logger settings.} -} -\if{html}{\out{
}} -} -\subsection{Returns}{ -None. -} -} } diff --git a/man/active.Rd b/man/active.Rd new file mode 100644 index 0000000..065b885 --- /dev/null +++ b/man/active.Rd @@ -0,0 +1,17 @@ +% Generated by roxygen2: do not edit by hand +% Please edit documentation in R/z-pkg-events.r +\docType{data} +\name{active} +\alias{active} +\title{Active Settings} +\format{ +An object of class \code{environment} of length 0. +} +\usage{ +active +} +\description{ +Package environment variable to hold +global level settings. +} +\keyword{datasets} diff --git a/man/apply_active_settings.Rd b/man/apply_active_settings.Rd new file mode 100644 index 0000000..f5d4593 --- /dev/null +++ b/man/apply_active_settings.Rd @@ -0,0 +1,27 @@ +% Generated by roxygen2: do not edit by hand +% Please edit documentation in R/config.R +\name{apply_active_settings} +\alias{apply_active_settings} +\title{Apply Active Logger Settings} +\usage{ +apply_active_settings(settings) +} +\arguments{ +\item{settings}{defined in the configuration} +} +\description{ +Parses and loads the settings specified +in the logger configuration and ensures +they are active in the environment. +} +\seealso{ +Other Configuration: +\code{\link{config_specification}()}, +\code{\link{create_log_levels}()}, +\code{\link{display_log_levels}()}, +\code{\link{ensure_logger}()}, +\code{\link{get_active_settings}()}, +\code{\link{load_log_layouts}()}, +\code{\link{wipe_logger}()} +} +\concept{Configuration} diff --git a/man/config_specification.Rd b/man/config_specification.Rd index 68b1a52..b132dcd 100644 --- a/man/config_specification.Rd +++ b/man/config_specification.Rd @@ -15,8 +15,11 @@ config. } \seealso{ Other Configuration: +\code{\link{apply_active_settings}()}, +\code{\link{create_log_levels}()}, \code{\link{display_log_levels}()}, \code{\link{ensure_logger}()}, +\code{\link{get_active_settings}()}, \code{\link{load_log_layouts}()}, \code{\link{wipe_logger}()} } diff --git a/man/create_log_levels.Rd b/man/create_log_levels.Rd new file mode 100644 index 0000000..0be2d27 --- /dev/null +++ b/man/create_log_levels.Rd @@ -0,0 +1,28 @@ +% Generated by roxygen2: do not edit by hand +% Please edit documentation in R/config.R +\name{create_log_levels} +\alias{create_log_levels} +\title{Attach Log Levels} +\usage{ +create_log_levels(definitions) +} +\arguments{ +\item{definitions}{defined in the configuration} +} +\description{ +Parses and loads the levels specified in the +logging configuration and registers them with the +dispatcher via the \code{log_levels} active +binding. +} +\seealso{ +Other Configuration: +\code{\link{apply_active_settings}()}, +\code{\link{config_specification}()}, +\code{\link{display_log_levels}()}, +\code{\link{ensure_logger}()}, +\code{\link{get_active_settings}()}, +\code{\link{load_log_layouts}()}, +\code{\link{wipe_logger}()} +} +\concept{Configuration} diff --git a/man/display_log_levels.Rd b/man/display_log_levels.Rd index b70277b..e00ec29 100644 --- a/man/display_log_levels.Rd +++ b/man/display_log_levels.Rd @@ -14,8 +14,11 @@ crayon styles. } \seealso{ Other Configuration: +\code{\link{apply_active_settings}()}, \code{\link{config_specification}()}, +\code{\link{create_log_levels}()}, \code{\link{ensure_logger}()}, +\code{\link{get_active_settings}()}, \code{\link{load_log_layouts}()}, \code{\link{wipe_logger}()} } diff --git a/man/ensure_logger.Rd b/man/ensure_logger.Rd index 3274bea..028be13 100644 --- a/man/ensure_logger.Rd +++ b/man/ensure_logger.Rd @@ -18,8 +18,11 @@ attached to the specified environment. } \seealso{ Other Configuration: +\code{\link{apply_active_settings}()}, \code{\link{config_specification}()}, +\code{\link{create_log_levels}()}, \code{\link{display_log_levels}()}, +\code{\link{get_active_settings}()}, \code{\link{load_log_layouts}()}, \code{\link{wipe_logger}()} } diff --git a/man/get_active_settings.Rd b/man/get_active_settings.Rd new file mode 100644 index 0000000..7cc3208 --- /dev/null +++ b/man/get_active_settings.Rd @@ -0,0 +1,23 @@ +% Generated by roxygen2: do not edit by hand +% Please edit documentation in R/config.R +\name{get_active_settings} +\alias{get_active_settings} +\title{Active Logger Settings} +\usage{ +get_active_settings() +} +\description{ +Gets the active global settings +for the logger. +} +\seealso{ +Other Configuration: +\code{\link{apply_active_settings}()}, +\code{\link{config_specification}()}, +\code{\link{create_log_levels}()}, +\code{\link{display_log_levels}()}, +\code{\link{ensure_logger}()}, +\code{\link{load_log_layouts}()}, +\code{\link{wipe_logger}()} +} +\concept{Configuration} diff --git a/man/load_log_layouts.Rd b/man/load_log_layouts.Rd index d48f17a..8068c4e 100644 --- a/man/load_log_layouts.Rd +++ b/man/load_log_layouts.Rd @@ -20,9 +20,12 @@ binding. } \seealso{ Other Configuration: +\code{\link{apply_active_settings}()}, \code{\link{config_specification}()}, +\code{\link{create_log_levels}()}, \code{\link{display_log_levels}()}, \code{\link{ensure_logger}()}, +\code{\link{get_active_settings}()}, \code{\link{wipe_logger}()} } \concept{Configuration} diff --git a/man/value.fmt_log_level.Rd b/man/value.fmt_log_level.Rd index 866ec72..2a81b3d 100644 --- a/man/value.fmt_log_level.Rd +++ b/man/value.fmt_log_level.Rd @@ -4,11 +4,13 @@ \alias{value.fmt_log_level} \title{Value} \usage{ -\method{value}{fmt_log_level}(obj, ...) +\method{value}{fmt_log_level}(obj, lvl_context, ...) } \arguments{ \item{obj}{object to extract value from.} +\item{lvl_context}{context to evaluate log level.} + \item{...}{further arguments passed to or from other methods.} } \value{ diff --git a/man/value.fmt_log_msg.Rd b/man/value.fmt_log_msg.Rd index 34206cf..5eb9eee 100644 --- a/man/value.fmt_log_msg.Rd +++ b/man/value.fmt_log_msg.Rd @@ -4,11 +4,13 @@ \alias{value.fmt_log_msg} \title{Value} \usage{ -\method{value}{fmt_log_msg}(obj, ...) +\method{value}{fmt_log_msg}(obj, msg_context, ...) } \arguments{ \item{obj}{object to extract value from.} +\item{msg_context}{context to evaluate log message.} + \item{...}{further arguments passed to or from other methods.} } \value{ diff --git a/man/wipe_logger.Rd b/man/wipe_logger.Rd index c8afcb5..0fbc208 100644 --- a/man/wipe_logger.Rd +++ b/man/wipe_logger.Rd @@ -15,9 +15,12 @@ from a previous load. } \seealso{ Other Configuration: +\code{\link{apply_active_settings}()}, \code{\link{config_specification}()}, +\code{\link{create_log_levels}()}, \code{\link{display_log_levels}()}, \code{\link{ensure_logger}()}, +\code{\link{get_active_settings}()}, \code{\link{load_log_layouts}()} } \concept{Configuration} diff --git a/tests/testthat/helper-objects.R b/tests/testthat/helper-objects.R index ccafbfe..03fb390 100644 --- a/tests/testthat/helper-objects.R +++ b/tests/testthat/helper-objects.R @@ -10,6 +10,10 @@ TestObject <- R6::R6Class( # nolint (class definition) self$cls_name <- private$get_class_name() }, + get_logger = function(name) { + globalenv()[[eval(name)]] + }, + identifier = function() { invisible(private$id) }, @@ -18,10 +22,11 @@ TestObject <- R6::R6Class( # nolint (class definition) invisible(self$cls_name) }, - invoke_logger = function() { - a <- "test"; b <- 123; c <- 100L + invoke_logger = function(name) { + logger <- self$get_logger(name) - Logger$trace("these are some variables: {a} - {b} - {c}") + a <- "test"; b <- 123; c <- 100L + logger$trace("these are some variables: {a} - {b} - {c}") } ), @@ -50,10 +55,12 @@ DerivedTestObject <- R6::R6Class( # nolint (class definition) super$initialize() }, - invoke_logger = function() { + invoke_logger = function(name) { + logger <- self$get_logger(name) + a <- "derived test"; b <- 321; c <- 200L - Logger$trace("variables in derived: {a} - {b} - {c}") + logger$trace("variables in derived: {a} - {b} - {c}") } ) ) @@ -67,9 +74,15 @@ UnassociatedTestObject <- R6::R6Class( # nolint (class definition) }, - invoke_logger = function() { + get_logger = function(name) { + globalenv()[[name]] + }, + + invoke_logger = function(name) { + logger <- self$get_logger(name) + a <- "derived test"; b <- 321; c <- 200L - Logger$trace("variables in derived: {a} - {b} - {c}") + logger$trace("variables in derived: {a} - {b} - {c}") } ), diff --git a/tests/testthat/test-cls-association.R b/tests/testthat/test-cls-association.R index 210badd..aff91f1 100644 --- a/tests/testthat/test-cls-association.R +++ b/tests/testthat/test-cls-association.R @@ -30,11 +30,11 @@ testthat::test_that( test_obj <- TestObject$new() - actual <- capture_output_lines({ - test_obj$invoke_logger() + actual <- testthat::capture_output_lines({ + test_obj$invoke_logger("Logger") }) - expect_equal(length(actual), 3) + expect_equal(length(actual), 4) expect_true(stringr::str_detect(actual[1], stringr::fixed("Object Id:"))) expect_true(stringr::str_detect(actual[1], stringr::fixed(test_obj$identifier()))) @@ -84,10 +84,10 @@ testthat::test_that( test_obj <- DerivedTestObject$new() actual <- capture_output_lines({ - test_obj$invoke_logger() + test_obj$invoke_logger("Logger") }) - expect_equal(length(actual), 3) + expect_equal(length(actual), 4) expect_true(stringr::str_detect(actual[1], stringr::fixed("Object Id:"))) expect_true(stringr::str_detect(actual[1], stringr::fixed(test_obj$identifier()))) diff --git a/tests/testthat/test-config.R b/tests/testthat/test-config.R index 62ba7e2..5814da4 100644 --- a/tests/testthat/test-config.R +++ b/tests/testthat/test-config.R @@ -1,37 +1,52 @@ testthat::test_that( - desc = "initialization_works", + desc = "init_levels_works", code = { - test_config_file <- system.file("test-data", + test_config_file <- system.file("test-data", "test-config.yaml", package = "dyn.log") - invisible(testthat::capture_output_lines({ - init_logger(file_path = test_config_file) - })) + config <- yaml::read_yaml(test_config_file, + eval.expr = TRUE) + + + actual <- create_log_levels(config$levels) + + log_levels <- log_levels() + + expect_true(any(match(log_levels, "trace"))) + expect_true(any(match(log_levels, "debug"))) + expect_true(any(match(log_levels, "info"))) + expect_true(any(match(log_levels, "success"))) + expect_true(any(match(log_levels, "warn"))) + expect_true(any(match(log_levels, "error"))) + expect_true(any(match(log_levels, "critical"))) + expect_true(any(match(log_levels, "fatal"))) + + expect_equal(length(actual), length(log_levels)) + } +) + +testthat::test_that( + desc = "init_settings_works", + code = { - settings <- Logger$get_settings() + test_config_file <- system.file("test-data", + "test-config.yaml", + package = "dyn.log") - expect_equal(settings$threshold, "TRACE") - expect_true(!is.null(settings$callstack)) - expect_equal(settings$callstack$max, 5) - expect_equal(settings$callstack$start, -1) - expect_equal(settings$callstack$stop, -1) + config <- yaml::read_yaml(test_config_file, + eval.expr = TRUE) - log_levels <- log_levels() + apply_active_settings(config$settings) - expect_true(any(match(log_levels, "trace"))) - expect_true(any(match(log_levels, "debug"))) - expect_true(any(match(log_levels, "info"))) - expect_true(any(match(log_levels, "success"))) - expect_true(any(match(log_levels, "warn"))) - expect_true(any(match(log_levels, "error"))) - expect_true(any(match(log_levels, "critical"))) - expect_true(any(match(log_levels, "fatal"))) + expect_equal(active$threshold$name, "TRACE") + expect_equal(active$threshold$severity, 600) + expect_true(!is.null(active$callstack)) - with(Logger$get_settings(), { - expect_equal(threshold, "TRACE") - }) + expect_equal(active$callstack$max, 5) + expect_equal(active$callstack$start, -1) + expect_equal(active$callstack$stop, -1) } ) @@ -44,7 +59,8 @@ testthat::test_that( expect_true(!is.null(log_configs$default)) expect_true(!is.null(log_configs$knitr)) expect_true(!is.null(log_configs$object)) -}) + } +) testthat::test_that( desc = "object_config_works", @@ -61,7 +77,7 @@ testthat::test_that( test_obj <- DerivedTestObject$new() actual <- capture_output_lines({ - test_obj$invoke_logger() + test_obj$invoke_logger("Logger") }) expect_equal(length(actual), 2) @@ -105,7 +121,7 @@ testthat::test_that( test_obj <- DerivedTestObject$new() actual <- capture_output_lines({ - test_obj$invoke_logger() + test_obj$invoke_logger("Logger") }) expect_equal(length(actual), 2) @@ -174,3 +190,26 @@ testthat::test_that( expect_true(identical(idx, integer())) } ) + +testthat::test_that( + desc = "log_levels_display", + code = { + + test_config_file <- system.file("test-data", + "test-config.yaml", + package = "dyn.log") + + init_logger(file_path = test_config_file) + + actual <- capture_output_lines({ + display_log_levels() + }) + + for (level in log_levels()) { + info <- level_info(level) + pattern <- paste(info$name, info$description) + + expect_true(any(!is.na(match(actual, pattern))), label = info$name) + } + } +) diff --git a/tests/testthat/test-dispatch.R b/tests/testthat/test-dispatch.R index ba9b971..34a7e13 100644 --- a/tests/testthat/test-dispatch.R +++ b/tests/testthat/test-dispatch.R @@ -21,54 +21,40 @@ test_that("test_log_threshold_works", { logger <- LogDispatch$new() - logger$private$settings$threshold <- "INFO" + active$threshold$name <- "INFO" + active$threshold$severity <- 400 actual <- capture_output({ var1 <- "abc"; var2 <- 123; var3 <- 0.7535651 logger$trace("log msg local vars: {var1}, {var2}, {var3}") }) - logger$private$settings$threshold <- "TRACE" + active$threshold$name <- "TRACE" + active$threshold$severity <- 600 expect_equal(actual, "") expect_false(stringr::str_detect(actual, stringr::fixed("TEST "))) expect_false(stringr::str_detect(actual, stringr::fixed("log msg local vars: abc, 123, 0.7535651"))) }) -test_that("test_can_set_log_settings", { - - test_config_file <- system.file("test-data", - "test-config.yaml", - package = "dyn.log") - - log_config <- yaml::read_yaml(test_config_file, eval.expr = TRUE) - - dispatch <- LogDispatchTester$new() - dispatch$set_settings(log_config$settings) - - actual <- dispatch$get_settings() - - expect_equal(actual, log_config$settings) -}) - test_that("test_add_log_level_works", { test_config_file <- system.file("test-data", "test-config.yaml", package = "dyn.log") - log_config <- yaml::read_yaml(test_config_file, eval.expr = TRUE) - - dispatch <- LogDispatchTester$new() - dispatch$set_settings(log_config$settings) + init_logger(file_path = test_config_file) - lvl <- new_log_level(name = "TEST", - description = "for testing", - severity = 42L, - log_style = crayon::blue, - msg_style = crayon::silver) + new_level <- new_log_level( + name = "TEST", + description = "for testing", + severity = 42L, + log_style = crayon::blue, + msg_style = crayon::silver + ) - dispatch$add_log_level(lvl) + dispatch <- LogDispatchTester$new() + dispatch$attach_log_level(new_level) actual <- capture_output({ var1 <- "abc"; var2 <- 123; var3 <- 0.7535651 @@ -82,7 +68,7 @@ test_that("test_add_log_level_works", { log_levels(name = "test", level = NA) all_levels <- log_levels() - expect_true(all(is.na(match(all_levels, tolower(level_name(lvl)))))) + expect_true(all(is.na(match(all_levels, tolower(level_name(new_level)))))) }) test_that("test_threshold_evaluation_works", { @@ -91,18 +77,16 @@ test_that("test_threshold_evaluation_works", { "test-config.yaml", package = "dyn.log") - log_config <- yaml::read_yaml(test_config_file, eval.expr = TRUE) - - dispatch <- LogDispatchTester$new() - dispatch$set_settings(log_config$settings) + init_logger(file_path = test_config_file) - lvl <- new_log_level(name = "TEST", + new_level <- new_log_level(name = "TEST", description = "for testing", severity = 100L, log_style = crayon::make_style("deepskyblue2")$bold, msg_style = crayon::silver) - dispatch$add_log_level(lvl) + dispatch <- LogDispatchTester$new() + dispatch$attach_log_level(new_level) log_fn <- dispatch[["test"]] @@ -119,5 +103,5 @@ test_that("test_threshold_evaluation_works", { log_levels(name = "test", level = NA) all_levels <- log_levels() - expect_true(all(is.na(match(all_levels, tolower(level_name(lvl)))))) + expect_true(all(is.na(match(all_levels, tolower(level_name(new_level)))))) }) diff --git a/tests/testthat/test-layout.R b/tests/testthat/test-layout.R index d8ecfc7..493a799 100644 --- a/tests/testthat/test-layout.R +++ b/tests/testthat/test-layout.R @@ -39,6 +39,7 @@ test_that("log_layout_format", { ) layouts <- log_layouts() + expect_true(!is.null(log_layout)) expect_equal(class(log_layout), "log_layout") @@ -92,9 +93,7 @@ test_that("log_layout_evaluates_simple_singleline", { log_layout <- new_log_layout( format = list( - new_fmt_log_level(), - new_fmt_timestamp(crayon::silver$italic), - new_fmt_log_msg() + new_fmt_timestamp(crayon::silver$italic) ) ) @@ -105,20 +104,18 @@ test_that("log_layout_evaluates_simple_singleline", { detail <- log_layout_detail(log_layout) expect_true(!is.null(detail)) - expect_equal(length(detail$formats), 3) - expect_equal(length(detail$types), 4) + expect_equal(length(detail$formats), 1) + expect_equal(length(detail$types), 2) actual <- evaluate_layout(detail, context) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed("{format(level)}"))) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed(" {format(level, message = {log_msg})}"))) + expect_true(stringr::str_detect(actual, pattern = format(Sys.Date(), "%m/%d/%Y"))) }) test_that("log_layout_evaluates_simple_multiline", { log_layout <- new_log_layout( format = list( - new_fmt_log_level(), new_fmt_timestamp(crayon::silver$italic), new_fmt_line_break(), new_fmt_log_msg() @@ -132,24 +129,21 @@ test_that("log_layout_evaluates_simple_multiline", { detail <- log_layout_detail(log_layout) expect_true(!is.null(detail)) - expect_equal(length(detail$formats), 4) - expect_equal(length(detail$types), 5) + expect_equal(length(detail$formats), 3) + expect_equal(length(detail$types), 4) actual <- evaluate_layout(detail, context) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed("{format(level)}"))) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed("\n{format(level, message = {log_msg})}"))) + expect_true(stringr::str_detect(actual, pattern = format(Sys.Date(), "%m/%d/%Y"))) }) test_that("log_layout_evaluates_metrics_singleline", { log_layout <- new_log_layout( format = list( - new_fmt_log_level(), new_fmt_metric(crayon::green$bold, "sysname"), new_fmt_metric(crayon::red$bold, "release"), - new_fmt_timestamp(crayon::silver$italic), - new_fmt_log_msg() + new_fmt_timestamp(crayon::silver$italic) ) ) @@ -158,15 +152,14 @@ test_that("log_layout_evaluates_metrics_singleline", { detail <- log_layout_detail(log_layout) expect_true(!is.null(detail)) - expect_equal(length(detail$formats), 5) - expect_equal(length(detail$types), 5) + expect_equal(length(detail$formats), 3) + expect_equal(length(detail$types), 3) context <- list(fmt_metric = sys_context()) actual <- evaluate_layout(detail, context) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed("{format(level)}"))) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed(" {format(level, message = {log_msg})}"))) + expect_true(stringr::str_detect(actual, pattern = format(Sys.Date(), "%m/%d/%Y"))) expect_true(stringr::str_detect(actual, pattern = stringr::fixed(Sys.info()[["sysname"]]))) expect_true(stringr::str_detect(actual, pattern = stringr::fixed(Sys.info()[["release"]]))) @@ -198,8 +191,7 @@ test_that("log_layout_evaluates_metrics_multiline", { actual <- evaluate_layout(detail, context) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed("\n{format(level)}"))) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed(" {format(level, message = {log_msg})}"))) + expect_true(stringr::str_detect(actual, pattern = format(Sys.Date(), "%m/%d/%Y"))) expect_true(stringr::str_detect(actual, pattern = stringr::fixed(Sys.info()[["sysname"]]))) expect_true(stringr::str_detect(actual, pattern = stringr::fixed(Sys.info()[["release"]]))) @@ -238,8 +230,7 @@ test_that("log_layout_evaluates_cls_attributes_multiline", { actual <- evaluate_layout(detail, context) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed("\n{format(level)}"))) - expect_true(stringr::str_detect(actual, pattern = stringr::fixed(" {format(level, message = {log_msg})}"))) + expect_true(stringr::str_detect(actual, pattern = format(Sys.Date(), "%m/%d/%Y"))) expect_true(stringr::str_detect(actual, pattern = stringr::fixed(Sys.info()[["sysname"]]))) expect_true(stringr::str_detect(actual, pattern = stringr::fixed(Sys.info()[["release"]]))) diff --git a/tests/testthat/test-level.R b/tests/testthat/test-level.R index 622d5bf..5075e68 100644 --- a/tests/testthat/test-level.R +++ b/tests/testthat/test-level.R @@ -142,23 +142,6 @@ testthat::test_that( } ) -testthat::test_that( - desc = "log_levels_display", - code = { - - actual <- capture_output_lines({ - display_log_levels() - }) - - for (level in log_levels()) { - info <- level_info(level) - pattern <- paste(info$name, info$description) - - expect_true(any(!is.na(match(actual, pattern))), label = info$name) - } - } -) - testthat::test_that( desc = "can_remove_log_level", code = { diff --git a/vignettes/Configuration.Rmd b/vignettes/Configuration.Rmd index 97ffbec..a551e27 100644 --- a/vignettes/Configuration.Rmd +++ b/vignettes/Configuration.Rmd @@ -216,7 +216,3 @@ As you can see, the logger knows to log contextual information about any object + **cls_name**": a public property which is calculated when the object is instantiated to get the correct run-time class name (since it is derived). This can be a powerful mechanic for templatizing important contextual information in your client applications or scripts. - -For a detailed look at layouts refer to the [Layouts](https://bmoretz.github.io/dyn.log/articles/Layouts.html) vignette online, or - -> vignette("Layouts", package = "dyn.log") diff --git a/vignettes/Formats.Rmd b/vignettes/Formats.Rmd index 861960c..1d07fc7 100644 --- a/vignettes/Formats.Rmd +++ b/vignettes/Formats.Rmd @@ -122,7 +122,8 @@ Execution scope formats give you the ability to log the context around the invoc context object, much like *sys_context*, called **exec_context**: ```{r, set_knitter_offset, echo=F} -callstack_settings <- Logger$get_settings()$callstack +settings <- dyn.log::get_active_settings() +callstack_settings <- settings$callstack ``` ```{r, exec_scope_ex, eval=T}