From 9e1b95c6eeafad0ff89659a710ae3dc2fa613a3d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?I=C3=B1aki=20=C3=9Acar?= Date: Tue, 5 Jun 2018 12:31:34 +0200 Subject: [PATCH 1/4] implement log levels --- R/RcppExports.R | 12 ++++++------ R/simmer-class.R | 6 +++--- R/simmer-methods.R | 5 +++-- R/trajectory-activities.R | 7 +++++-- R/trajectory-class.R | 8 ++++---- inst/include/simmer/activity/log.h | 12 ++++++++---- inst/include/simmer/simulator.h | 13 ++++++++----- man/log_.Rd | 6 +++++- man/simmer.Rd | 5 ++++- src/RcppExports.cpp | 27 +++++++++++++++------------ src/activity.cpp | 8 ++++---- src/simulator.cpp | 4 ++-- 12 files changed, 67 insertions(+), 46 deletions(-) diff --git a/R/RcppExports.R b/R/RcppExports.R index d8a7f03d..97f71e86 100644 --- a/R/RcppExports.R +++ b/R/RcppExports.R @@ -257,12 +257,12 @@ Wait__new <- function() { .Call(`_simmer_Wait__new`) } -Log__new <- function(message) { - .Call(`_simmer_Log__new`, message) +Log__new <- function(message, level) { + .Call(`_simmer_Log__new`, message, level) } -Log__new_func <- function(message) { - .Call(`_simmer_Log__new_func`, message) +Log__new_func <- function(message, level) { + .Call(`_simmer_Log__new_func`, message, level) } activity_get_count_ <- function(activity_) { @@ -357,8 +357,8 @@ get_queue_count_selected_ <- function(sim_, id) { .Call(`_simmer_get_queue_count_selected_`, sim_, id) } -Simulator__new <- function(name, verbose, mon) { - .Call(`_simmer_Simulator__new`, name, verbose, mon) +Simulator__new <- function(name, verbose, mon, log_level) { + .Call(`_simmer_Simulator__new`, name, verbose, mon, log_level) } reset_ <- function(sim_) { diff --git a/R/simmer-class.R b/R/simmer-class.R index d33e81e0..a9166f14 100644 --- a/R/simmer-class.R +++ b/R/simmer-class.R @@ -2,11 +2,11 @@ Simmer <- R6Class("simmer", public = list( name = NA, - initialize = function(name="anonymous", verbose=FALSE, mon=monitor_mem()) { - check_args(name="string", verbose="flag", mon="monitor") + initialize = function(name="anonymous", verbose=FALSE, mon=monitor_mem(), log_level=0) { + check_args(name="string", verbose="flag", mon="monitor", log_level="number") self$name <- name private$mon <- mon - private$sim_obj <- Simulator__new(name, verbose, mon$get_xptr()) + private$sim_obj <- Simulator__new(name, verbose, mon$get_xptr(), log_level) self }, diff --git a/R/simmer-methods.R b/R/simmer-methods.R index 04306304..6f55455b 100644 --- a/R/simmer-methods.R +++ b/R/simmer-methods.R @@ -6,6 +6,7 @@ #' @param verbose enable showing activity information. #' @param mon monitor (in memory by default); see \code{\link{monitor}} for #' other options. +#' @param log_level debugging level (see \code{\link{log_}}). #' #' @return Returns a simulation environment. #' @seealso @@ -49,8 +50,8 @@ #' env %>% peek() # time for the next event #' env %>% stepn() # execute next event #' -simmer <- function(name="anonymous", verbose=FALSE, mon=monitor_mem()) - Simmer$new(name, verbose, mon) +simmer <- function(name="anonymous", verbose=FALSE, mon=monitor_mem(), log_level=0) + Simmer$new(name, verbose, mon, log_level) #' Reset a Simulator #' diff --git a/R/trajectory-activities.R b/R/trajectory-activities.R index 99e70487..c7baf587 100644 --- a/R/trajectory-activities.R +++ b/R/trajectory-activities.R @@ -483,10 +483,13 @@ wait.trajectory <- function(.trj) .trj$wait() #' @inheritParams seize #' @param message the message to display, accepts either a string or a callable object #' (a function) which must return a string. +#' @param level debugging level. The \code{message} will be printed if, and only if, +#' the \code{level} provided is less or equal to the \code{log_level} defined in the +#' simulation environment (see \code{\link{simmer}}). #' #' @return Returns the trajectory object. #' @export -log_ <- function(.trj, message) UseMethod("log_") +log_ <- function(.trj, message, level=0) UseMethod("log_") #' @export -log_.trajectory <- function(.trj, message) .trj$log(message) +log_.trajectory <- function(.trj, message, level=0) .trj$log(message, level) diff --git a/R/trajectory-class.R b/R/trajectory-class.R index 194053ca..4c02c7c1 100644 --- a/R/trajectory-class.R +++ b/R/trajectory-class.R @@ -346,12 +346,12 @@ Trajectory <- R6Class("trajectory", wait = function() { private$add_activity(Wait__new()) }, - log = function(message) { - check_args(message=c("string", "function")) + log = function(message, level=0) { + check_args(message=c("string", "function"), level="number") switch( binarise(is.function(message)), - private$add_activity(Log__new(message)), - private$add_activity(Log__new_func(message)) + private$add_activity(Log__new(message, level)), + private$add_activity(Log__new_func(message, level)) ) } ), diff --git a/inst/include/simmer/activity/log.h b/inst/include/simmer/activity/log.h index a4778130..18a99947 100644 --- a/inst/include/simmer/activity/log.h +++ b/inst/include/simmer/activity/log.h @@ -14,21 +14,25 @@ namespace simmer { public: CLONEABLE(Log) - Log(const T& message) : Activity("Log"), message(message) {} + Log(const T& message, int level) + : Activity("Log"), message(message), level(level) {} void print(unsigned int indent = 0, bool verbose = false, bool brief = false) { Activity::print(indent, verbose, brief); - internal::print(brief, true, "message", ""); + internal::print(brief, true, "message", "message", ARG(level)); } double run(Arrival* arrival) { - Rcpp::Rcout << arrival->sim->now() << ": " << arrival->name << ": " << - get(message, arrival) << std::endl; + int log_level = arrival->sim->log_level; + if (log_level < 0 || (level >= 0 && log_level >= level)) + Rcpp::Rcout << arrival->sim->now() << ": " << arrival->name << ": " << + get(message, arrival) << std::endl; return 0; } protected: T message; + int level; }; } // namespace simmer diff --git a/inst/include/simmer/simulator.h b/inst/include/simmer/simulator.h index f3c53c6d..f66c57cd 100644 --- a/inst/include/simmer/simulator.h +++ b/inst/include/simmer/simulator.h @@ -50,15 +50,18 @@ namespace simmer { std::string name; bool verbose; Monitor* mon; + int log_level; /** * Constructor. - * @param name simulator name - * @param verbose verbose flag - * @param mon monitoring object + * @param name simulator name + * @param verbose verbose flag + * @param mon monitoring object + * @param log_level debugging level (for activities) */ - Simulator(const std::string& name, bool verbose, Monitor* mon) - : name(name), verbose(verbose), mon(mon), now_(0), process_(NULL), b_count(0) {} + Simulator(const std::string& name, bool verbose, Monitor* mon, int log_level) + : name(name), verbose(verbose), mon(mon), log_level(log_level), now_(0), + process_(NULL), b_count(0) {} ~Simulator(); diff --git a/man/log_.Rd b/man/log_.Rd index 955bb0ef..14e6c4e3 100644 --- a/man/log_.Rd +++ b/man/log_.Rd @@ -4,13 +4,17 @@ \alias{log_} \title{Logging} \usage{ -log_(.trj, message) +log_(.trj, message, level = 0) } \arguments{ \item{.trj}{the trajectory object.} \item{message}{the message to display, accepts either a string or a callable object (a function) which must return a string.} + +\item{level}{debugging level. The \code{message} will be printed if, and only if, +the \code{level} provided is less or equal to the \code{log_level} defined in the +simulation environment (see \code{\link{simmer}}).} } \value{ Returns the trajectory object. diff --git a/man/simmer.Rd b/man/simmer.Rd index 31fa39a5..00a983de 100644 --- a/man/simmer.Rd +++ b/man/simmer.Rd @@ -4,7 +4,8 @@ \alias{simmer} \title{Create a Simulator} \usage{ -simmer(name = "anonymous", verbose = FALSE, mon = monitor_mem()) +simmer(name = "anonymous", verbose = FALSE, mon = monitor_mem(), + log_level = 0) } \arguments{ \item{name}{the name of the simulator.} @@ -13,6 +14,8 @@ simmer(name = "anonymous", verbose = FALSE, mon = monitor_mem()) \item{mon}{monitor (in memory by default); see \code{\link{monitor}} for other options.} + +\item{log_level}{debugging level (see \code{\link{log_}}).} } \value{ Returns a simulation environment. diff --git a/src/RcppExports.cpp b/src/RcppExports.cpp index 03b8962f..bfa64195 100644 --- a/src/RcppExports.cpp +++ b/src/RcppExports.cpp @@ -802,24 +802,26 @@ BEGIN_RCPP END_RCPP } // Log__new -SEXP Log__new(const std::string& message); -RcppExport SEXP _simmer_Log__new(SEXP messageSEXP) { +SEXP Log__new(const std::string& message, int level); +RcppExport SEXP _simmer_Log__new(SEXP messageSEXP, SEXP levelSEXP) { BEGIN_RCPP Rcpp::RObject rcpp_result_gen; Rcpp::RNGScope rcpp_rngScope_gen; Rcpp::traits::input_parameter< const std::string& >::type message(messageSEXP); - rcpp_result_gen = Rcpp::wrap(Log__new(message)); + Rcpp::traits::input_parameter< int >::type level(levelSEXP); + rcpp_result_gen = Rcpp::wrap(Log__new(message, level)); return rcpp_result_gen; END_RCPP } // Log__new_func -SEXP Log__new_func(const Function& message); -RcppExport SEXP _simmer_Log__new_func(SEXP messageSEXP) { +SEXP Log__new_func(const Function& message, int level); +RcppExport SEXP _simmer_Log__new_func(SEXP messageSEXP, SEXP levelSEXP) { BEGIN_RCPP Rcpp::RObject rcpp_result_gen; Rcpp::RNGScope rcpp_rngScope_gen; Rcpp::traits::input_parameter< const Function& >::type message(messageSEXP); - rcpp_result_gen = Rcpp::wrap(Log__new_func(message)); + Rcpp::traits::input_parameter< int >::type level(levelSEXP); + rcpp_result_gen = Rcpp::wrap(Log__new_func(message, level)); return rcpp_result_gen; END_RCPP } @@ -1093,15 +1095,16 @@ BEGIN_RCPP END_RCPP } // Simulator__new -SEXP Simulator__new(const std::string& name, bool verbose, SEXP mon); -RcppExport SEXP _simmer_Simulator__new(SEXP nameSEXP, SEXP verboseSEXP, SEXP monSEXP) { +SEXP Simulator__new(const std::string& name, bool verbose, SEXP mon, int log_level); +RcppExport SEXP _simmer_Simulator__new(SEXP nameSEXP, SEXP verboseSEXP, SEXP monSEXP, SEXP log_levelSEXP) { BEGIN_RCPP Rcpp::RObject rcpp_result_gen; Rcpp::RNGScope rcpp_rngScope_gen; Rcpp::traits::input_parameter< const std::string& >::type name(nameSEXP); Rcpp::traits::input_parameter< bool >::type verbose(verboseSEXP); Rcpp::traits::input_parameter< SEXP >::type mon(monSEXP); - rcpp_result_gen = Rcpp::wrap(Simulator__new(name, verbose, mon)); + Rcpp::traits::input_parameter< int >::type log_level(log_levelSEXP); + rcpp_result_gen = Rcpp::wrap(Simulator__new(name, verbose, mon, log_level)); return rcpp_result_gen; END_RCPP } @@ -1310,8 +1313,8 @@ static const R_CallMethodDef CallEntries[] = { {"_simmer_UnTrap__new", (DL_FUNC) &_simmer_UnTrap__new, 1}, {"_simmer_UnTrap__new_func", (DL_FUNC) &_simmer_UnTrap__new_func, 1}, {"_simmer_Wait__new", (DL_FUNC) &_simmer_Wait__new, 0}, - {"_simmer_Log__new", (DL_FUNC) &_simmer_Log__new, 1}, - {"_simmer_Log__new_func", (DL_FUNC) &_simmer_Log__new_func, 1}, + {"_simmer_Log__new", (DL_FUNC) &_simmer_Log__new, 2}, + {"_simmer_Log__new_func", (DL_FUNC) &_simmer_Log__new_func, 2}, {"_simmer_activity_get_count_", (DL_FUNC) &_simmer_activity_get_count_, 1}, {"_simmer_activity_print_", (DL_FUNC) &_simmer_activity_print_, 3}, {"_simmer_activity_get_next_", (DL_FUNC) &_simmer_activity_get_next_, 1}, @@ -1335,7 +1338,7 @@ static const R_CallMethodDef CallEntries[] = { {"_simmer_get_server_count_selected_", (DL_FUNC) &_simmer_get_server_count_selected_, 2}, {"_simmer_get_queue_count_", (DL_FUNC) &_simmer_get_queue_count_, 2}, {"_simmer_get_queue_count_selected_", (DL_FUNC) &_simmer_get_queue_count_selected_, 2}, - {"_simmer_Simulator__new", (DL_FUNC) &_simmer_Simulator__new, 3}, + {"_simmer_Simulator__new", (DL_FUNC) &_simmer_Simulator__new, 4}, {"_simmer_reset_", (DL_FUNC) &_simmer_reset_, 1}, {"_simmer_now_", (DL_FUNC) &_simmer_now_, 1}, {"_simmer_peek_", (DL_FUNC) &_simmer_peek_, 2}, diff --git a/src/activity.cpp b/src/activity.cpp index c848cb09..fac75092 100644 --- a/src/activity.cpp +++ b/src/activity.cpp @@ -357,13 +357,13 @@ SEXP UnTrap__new_func(const Function& signals) { SEXP Wait__new() { return XPtr(new Wait()); } //[[Rcpp::export]] -SEXP Log__new(const std::string& message) { - return XPtr >(new Log(message)); +SEXP Log__new(const std::string& message, int level) { + return XPtr >(new Log(message, level)); } //[[Rcpp::export]] -SEXP Log__new_func(const Function& message) { - return XPtr >(new Log(message)); +SEXP Log__new_func(const Function& message, int level) { + return XPtr >(new Log(message, level)); } //[[Rcpp::export]] diff --git a/src/simulator.cpp b/src/simulator.cpp index c41789dd..032aeee2 100644 --- a/src/simulator.cpp +++ b/src/simulator.cpp @@ -4,8 +4,8 @@ using namespace Rcpp; using namespace simmer; //[[Rcpp::export]] -SEXP Simulator__new(const std::string& name, bool verbose, SEXP mon) { - return XPtr(new Simulator(name, verbose, XPtr(mon))); +SEXP Simulator__new(const std::string& name, bool verbose, SEXP mon, int log_level) { + return XPtr(new Simulator(name, verbose, XPtr(mon), log_level)); } //[[Rcpp::export]] From 534c2a8cb6940eb77ae81259401e6601aff721d4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?I=C3=B1aki=20=C3=9Acar?= Date: Tue, 5 Jun 2018 13:04:10 +0200 Subject: [PATCH 2/4] add tests --- tests/testthat/test-trajectory-log.R | 42 +++++++++++++++++++--------- 1 file changed, 29 insertions(+), 13 deletions(-) diff --git a/tests/testthat/test-trajectory-log.R b/tests/testthat/test-trajectory-log.R index fd3b3cb6..c9df00e3 100644 --- a/tests/testthat/test-trajectory-log.R +++ b/tests/testthat/test-trajectory-log.R @@ -1,21 +1,37 @@ context("log") -test_that("a message is correctly printed (1)", { +test_that("messages are correctly printed depending on the log_level", { t <- trajectory() %>% - log_("hello world!") + log_(function() "Message 0") %>% + log_("Message 1", level=1) %>% + log_("Message 2", level=2) %>% + log_("Message 3", level=Inf) - env <- simmer(verbose = TRUE) %>% - add_generator("entity", t, at(5)) + expect_output( + simmer(verbose=TRUE) %>% + add_generator("dummy", t, at(5)) %>% + run(), + "5: dummy0: Message 0" + ) - expect_output(run(env), "5: entity0: hello world!") -}) - -test_that("a message is correctly printed (2)", { - t <- trajectory() %>% - log_(function() "hello world!") + expect_output( + simmer(verbose=TRUE, log_level=1) %>% + add_generator("dummy", t, at(5)) %>% + run(), + "5: dummy0: Message 0.*5: dummy0: Message 1" + ) - env <- simmer(verbose = TRUE) %>% - add_generator("entity", t, at(5)) + expect_output( + simmer(verbose=TRUE, log_level=5) %>% + add_generator("dummy", t, at(5)) %>% + run(), + "5: dummy0: Message 0.*5: dummy0: Message 1.*5: dummy0: Message 2" + ) - expect_output(run(env), "5: entity0: hello world!") + expect_output( + simmer(verbose=TRUE, log_level=Inf) %>% + add_generator("dummy", t, at(5)) %>% + run(), + "5: dummy0: Message 0.*5: dummy0: Message 1.*5: dummy0: Message 2.*5: dummy0: Message 3" + ) }) From cfe604d162221283843011fa334659438164e729 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?I=C3=B1aki=20=C3=9Acar?= Date: Tue, 5 Jun 2018 15:40:11 +0200 Subject: [PATCH 3/4] update log_ description in vignette --- vignettes/simmer-03-trajectories.Rmd | 20 ++++++++++++++------ 1 file changed, 14 insertions(+), 6 deletions(-) diff --git a/vignettes/simmer-03-trajectories.Rmd b/vignettes/simmer-03-trajectories.Rmd index ff4fab47..16e82a8a 100644 --- a/vignettes/simmer-03-trajectories.Rmd +++ b/vignettes/simmer-03-trajectories.Rmd @@ -86,17 +86,25 @@ Additionally, you may want to try the `simmer.bricks` package, a plugin for `sim ### `log_()` -The `log_(., message`) method just prints a given message preceded by the simulation time and the name of the arrival, for debugging purposes: +The `log_(., message, level`) method just prints a given message preceded by the simulation time and the name of the arrival, for debugging purposes. The logging level is defined in the simulation environment: ```{r} -set.seed(1234) - t <- trajectory() %>% - log_("hello world!") + log_("this is always printed") %>% # level = 0 by default + log_("this is printed if `log_level>=1`", level = 1) %>% + log_("this is printed if `log_level>=2`", level = 2) simmer() %>% - add_generator("dummy", t, function() rexp(1, 1)) %>% - run(5) %>% invisible + add_generator("dummy", t, at(0)) %>% + run() %>% invisible + +simmer(log_level = 1) %>% + add_generator("dummy", t, at(0)) %>% + run() %>% invisible + +simmer(log_level = Inf) %>% + add_generator("dummy", t, at(0)) %>% + run() %>% invisible ``` ### `set_attribute()` From 480818fed5af43091a175a775259f47cf4fd87db Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?I=C3=B1aki=20=C3=9Acar?= Date: Tue, 5 Jun 2018 15:43:52 +0200 Subject: [PATCH 4/4] update NEWS [ci skip] --- NEWS.md | 1 + 1 file changed, 1 insertion(+) diff --git a/NEWS.md b/NEWS.md index 29691efa..ba666042 100644 --- a/NEWS.md +++ b/NEWS.md @@ -4,6 +4,7 @@ * The C++ core has been refactorised into a header-only library under `inst/include` (#147 closing #145). Therefore, from now on it is possible to extend the C++ API from another package by listing `simmer` under the `LinkingTo` field in the DESCRIPTION file. * New generic `monitor` constructor enables the development of new monitoring backends in other packages (179f656, as part of #147). +* New simulation-scoped logging levels. The `log_` activity has a new argument `level` which determines whether the message is printed depending on a global `log_level` defined in the `simmer` constructor (#152). ## Minor changes and fixes: