diff --git a/DESCRIPTION b/DESCRIPTION index aa34777..2937b09 100644 --- a/DESCRIPTION +++ b/DESCRIPTION @@ -21,7 +21,7 @@ Imports: DBI, later (>= 1.0.0), R6, - rlang + rlang (>= 1.0.0) Suggests: covr, dbplyr, diff --git a/NEWS.md b/NEWS.md index f44bcee..2138566 100644 --- a/NEWS.md +++ b/NEWS.md @@ -1,5 +1,8 @@ # pool (development version) +* Pool errors and warnings have been reviewed with an eye to making them + more immediately actionable (#145). + * Added support for SAP HANA databases (@marcosci, #103). # pool 0.1.6 diff --git a/R/DBI.R b/R/DBI.R index f7a347c..f313ee9 100644 --- a/R/DBI.R +++ b/R/DBI.R @@ -45,7 +45,7 @@ dbPool <- function(drv, # Force dots dots <- list(...) if (length(dots) > 0 && !is_named(dots)) { - stop("All arguments to `dbPool` must be named") + abort("All arguments to `dbPool` must be named") } state <- new.env(parent = emptyenv()) diff --git a/R/pool-methods.R b/R/pool-methods.R index 87aa590..ee63b4e 100644 --- a/R/pool-methods.R +++ b/R/pool-methods.R @@ -44,7 +44,8 @@ poolCreate <- function(factory, maxSize, idleTimeout, validationInterval, - state + state, + error_call = current_env() ) } diff --git a/R/pool.R b/R/pool.R index b5977a1..b045e83 100644 --- a/R/pool.R +++ b/R/pool.R @@ -12,7 +12,7 @@ Pool <- R6::R6Class("Pool", ## initialize the pool with min number of objects initialize = function(factory, minSize, maxSize, - idleTimeout, validationInterval, state) { + idleTimeout, validationInterval, state, error_call = caller_env()) { self$valid <- TRUE self$counters <- new.env(parent = emptyenv()) @@ -20,6 +20,9 @@ Pool <- R6::R6Class("Pool", self$counters$taken <- 0 private$idCounter <- 1 + if (!is.function(factory)) { + abort("`factory` must be a function.", call = error_call) + } private$factory <- factory self$minSize <- minSize self$maxSize <- maxSize @@ -31,14 +34,17 @@ Pool <- R6::R6Class("Pool", private$freeObjects <- new.env(parent = emptyenv()) for (i in seq_len(self$minSize)) { - private$createObject() + private$createObject(error_call = error_call) } }, ## calls activate and returns an object - fetch = function() { + fetch = function(error_call = caller_env()) { if (!self$valid) { - stop("This pool is no longer valid. Cannot fetch new objects.") + abort( + "This pool is no longer valid. Cannot fetch new objects.", + call = error_call + ) } ## see if there's any free objects @@ -52,12 +58,12 @@ Pool <- R6::R6Class("Pool", } else { ## if we get here, there are no free objects ## and we must create a new one - object <- private$createObject() + object <- private$createObject(error_call = error_call) } private$cancelScheduledTask(object, "validateHandle") ## call onActivate, onValidate and change object status - object <- private$checkValid(object) + object <- private$checkValid(object, error_call = error_call) private$changeObjectStatus(object, "taken") return(object) @@ -66,13 +72,13 @@ Pool <- R6::R6Class("Pool", ## passivates the object and returns it back to the pool ## (sets up task to destroy the object if the number of ## total objects exceeds the minimum) - release = function(object) { + release = function(object, error_call = caller_env()) { pool_metadata <- attr(object, "pool_metadata", exact = TRUE) if (pool_metadata$state == "free") { - stop("This object was already returned to the pool.") + abort("This object was already returned to the pool.", call = error_call) } if (is.null(pool_metadata) || !pool_metadata$valid) { - stop("Invalid object.") + abort("Invalid object.", call = error_call) } ## immediately destroy object if pool has already been closed if (!self$valid) { @@ -85,14 +91,19 @@ Pool <- R6::R6Class("Pool", onPassivate(object) }, error = function(e) { private$changeObjectStatus(object, NULL) - stop("Object could not be returned back to the pool. ", - "It was destroyed instead. Error message: ", - conditionMessage(e)) + abort( + c( + "Object could not be returned back to the pool.", + "It was destroyed instead" + ), + call = error_call, + parent = e + ) }) ## set up a task to destroy the object after `idleTimeout` ## secs, if we're over the minimum number of objects - taskHandle <- scheduleTask( + taskHandle <- later::later( function() { if (self$counters$free + self$counters$taken > self$minSize) { private$changeObjectStatus(object, NULL) @@ -119,7 +130,7 @@ Pool <- R6::R6Class("Pool", ## immediately destroy them). Objects can no longer be ## checked out from the pool. close = function() { - if (!self$valid) stop("The pool was already closed.") + if (!self$valid) abort("The pool was already closed.") self$valid <- FALSE freeEnv <- private$freeObjects @@ -132,11 +143,10 @@ Pool <- R6::R6Class("Pool", # check if there are taken objects if (self$counters$taken > 0) { - warning("You still have checked out objects. Return ", - "them to the pool so they can be destroyed. ", - "(If these are leaked objects - no reference ", - "- they will be destroyed the next time the ", - "garbage collector runs).", call. = FALSE) + pool_warn(c( + "You still have checked out objects.", + "Use `poolReturn()` them to the pool so they can be destroyed." + )) } } ), @@ -149,16 +159,20 @@ Pool <- R6::R6Class("Pool", ## creates an object, assigns it to the ## free environment and returns it - createObject = function() { + createObject = function(error_call = parent.frame()) { if (self$counters$free + self$counters$taken >= self$maxSize) { - stop("Maximum number of objects in pool has been reached") + abort("Maximum number of objects in pool has been reached", call = error_call) } object <- private$factory() if (is.null(object)) { - stop("Object creation was not successful. The `factory` ", - "argument must be a function that creates and ", - "returns the object to be pooled.") + abort( + c( + "Object creation failed.", + "The `factory` must not return `NULL`" + ), + call = error_call + ) } ## attach metadata about the object @@ -176,7 +190,10 @@ Pool <- R6::R6Class("Pool", ## detect leaked connections and destroy them reg.finalizer(pool_metadata, function(e) { if (pool_metadata$valid) { - warning("You have a leaked pooled object.") + pool_warn(c( + "Checked-out object deleted before being returned.", + "Make sure to `poolReturn()` all objects retrieved with `poolCheckout().`" + )) } }, onexit = TRUE) @@ -189,7 +206,7 @@ Pool <- R6::R6Class("Pool", tryCatch({ pool_metadata <- attr(object, "pool_metadata", exact = TRUE) if (!pool_metadata$valid) { - warning("Object was destroyed twice.") + pool_warn("Object was destroyed twice.") return() } pool_metadata$valid <- FALSE @@ -197,11 +214,11 @@ Pool <- R6::R6Class("Pool", private$cancelScheduledTask(object, "destroyHandle") onDestroy(object) }, error = function(e) { - warning("Object of class ", is(object)[1], - " could not be destroyed properly, ", - "but was successfully removed from pool. ", - "Error message: ", conditionMessage(e)) - + pool_warn(c( + "Object could not be destroyed, but was removed from the pool.", + "Error message:", + prefix(conditionMessage(e), " ") + )) }) }, @@ -224,7 +241,7 @@ Pool <- R6::R6Class("Pool", if (exists(id, envir = removeFrom)) { rm(list = id, envir = removeFrom) } else { - stop("The object could not be found.") + abort("Object could not be found.") } } self$counters[[from]] <- self$counters[[from]] - 1 @@ -256,40 +273,42 @@ Pool <- R6::R6Class("Pool", } }, - ## try to validate + activate an object; if that fails, - ## destroy the object and run whatever more cleanup is - ## necessary (provided through `errorFun`) - checkValidTemplate = function(object, errorFun) { - tryCatch({ - onActivate(object) - private$validate(object) - return(object) + ## tries to validate + activate the object; if that fails, + ## warn, destroy that object and try once more + ## if second attempt fails, throw an error + checkValid = function(object, error_call = caller_env()) { + tryCatch( + { + private$activateAndValidate(object) + return(object) + }, + error = function(e) {} + ) - }, error = function(e) { - private$changeObjectStatus(object, NULL) - errorFun(e) - }) + pool_warn(c( + "Failed to activate and/or validate existing object.", + "Trying again with a new object." + )) + private$changeObjectStatus(object, NULL) + object <- private$createObject() + + withCallingHandlers( + private$activateAndValidate(object), + error = function(e) { + private$changeObjectStatus(object, NULL) + abort( + "Freshly created object does not appear to be valid.", + call = error_call, + parent = e + ) + } + ) + object }, - ## tries to validate + activate the object; if that fails, - ## the first time around, warn, destroy that object and try - ## again with a new object; **returns** the object - ## if both tries fail, throw an error - checkValid = function(object) { - object <- private$checkValidTemplate(object, - function(e) { - warning("It wasn't possible to activate and/or validate ", - "the object. Trying again with a new object.", - call. = FALSE) - - private$checkValidTemplate(private$createObject(), - function(e) { - stop("Object does not appear to be valid. ", - "Error message: ", conditionMessage(e), - call. = FALSE) - }) - }) - return(object) + activateAndValidate = function(object) { + onActivate(object) + private$validate(object) }, ## run onValidate on the object only if over `validationInterval` @@ -312,3 +331,17 @@ Pool <- R6::R6Class("Pool", } ) ) + + +pool_warn <- function(messages) { + file <- if (is_testing()) stdout() else stderr() + + out <- paste0(messages, "\n", collapse = "") + cat(prefix(out, " "), file = file) +} +prefix <- function(x, prefix) { + gsub("(?m)^", prefix, x, perl = TRUE) +} +is_testing <- function() { + identical(Sys.getenv("TESTTHAT"), "true") +} diff --git a/R/scheduler.R b/R/scheduler.R index ba72b7a..dddc17c 100644 --- a/R/scheduler.R +++ b/R/scheduler.R @@ -1,26 +1,3 @@ -## Used in the Pool class to schedule and cancel tasks (based on `later`) -scheduleTask <- function(func, delay) { - force(func) - cancel <- later::later(function() { - # Make sure warn is at least 1 so that warnings are emitted immediately. - # (warn=2 is also OK, for use in debugging.) - warn_level <- getOption("warn") - if (is.numeric(warn_level) && !is.na(warn_level) && warn_level < 1) { - op <- options(warn = 1) - on.exit(options(op), add = TRUE) - } - if (!is.null(func)) - func() - }, delay) - - ## return value is a function that cancel the task, so the user can - ## cancel the task by calling the return value of `scheduleTask`. E.g: - ## > cancel <- scheduleTaskRecurring(function() print("hello"), 1) - ## [1] "hello" - ## [1] "hello" - cancel -} - ## Used in the Pool class. This function builds on top of `scheduleTask` ## to schedule recurring tasks. It uses the same mechanics: the return ## value is a function that cancels the scheduling of future tasks. @@ -30,9 +7,9 @@ scheduleTaskRecurring <- function(func, delay) { func2 <- function() { func() if (!cancelled) - handle <<- scheduleTask(func2, delay) + handle <<- later::later(func2, delay) } - handle <- scheduleTask(func2, delay) + handle <- later::later(func2, delay) function() { cancelled <<- TRUE diff --git a/tests/testthat/_snaps/create-destroy.md b/tests/testthat/_snaps/create-destroy.md new file mode 100644 index 0000000..0974929 --- /dev/null +++ b/tests/testthat/_snaps/create-destroy.md @@ -0,0 +1,24 @@ +# createObject throws if `factory` throws or returns NULL + + Code + poolCreate(MockPooledObj) + Condition + Error in `poolCreate()`: + ! `factory` must be a function. + Code + poolCreate(function(x) NULL) + Condition + Error in `poolCreate()`: + ! Object creation failed. + * The `factory` must not return `NULL` + +# useful warning if onDestroy fails + + Code + poolReturn(b) + later::run_now() + Output + Object could not be destroyed, but was removed from the pool. + Error message: + Destruction failed... + diff --git a/tests/testthat/_snaps/fetch.md b/tests/testthat/_snaps/fetch.md new file mode 100644 index 0000000..94c4b93 --- /dev/null +++ b/tests/testthat/_snaps/fetch.md @@ -0,0 +1,55 @@ +# fetch: throws if onActivate fails + + Code + poolCheckout(pool) + Output + Failed to activate and/or validate existing object. + Trying again with a new object. + Condition + Error in `poolCheckout()`: + ! Freshly created object does not appear to be valid. + Caused by error in `onActivate()`: + ! Activation failed... + +# fetch: throws if onValidate fails + + Code + poolCheckout(pool) + Output + Failed to activate and/or validate existing object. + Trying again with a new object. + Condition + Error in `poolCheckout()`: + ! Freshly created object does not appear to be valid. + Caused by error in `onValidate()`: + ! Validation failed... + +# fetch: warns if validation fails once, creates new object and tries again + + Code + obj <- get_private(pool)$checkValid(badObject) + Output + Failed to activate and/or validate existing object. + Trying again with a new object. + +--- + + Code + get_private(pool)$checkValid(obj) + Output + Failed to activate and/or validate existing object. + Trying again with a new object. + Condition + Error: + ! Freshly created object does not appear to be valid. + Caused by error in `onValidate()`: + ! Validation failed... + +# fetch: throws if the pool was closed + + Code + poolCheckout(pool) + Condition + Error in `poolCheckout()`: + ! This pool is no longer valid. Cannot fetch new objects. + diff --git a/tests/testthat/_snaps/pool.md b/tests/testthat/_snaps/pool.md new file mode 100644 index 0000000..92f9650 --- /dev/null +++ b/tests/testthat/_snaps/pool.md @@ -0,0 +1,8 @@ +# object operations: enforces maxSize + + Code + poolCheckout(pool) + Condition + Error in `poolCheckout()`: + ! Maximum number of objects in pool has been reached + diff --git a/tests/testthat/_snaps/release.md b/tests/testthat/_snaps/release.md new file mode 100644 index 0000000..10b5333 --- /dev/null +++ b/tests/testthat/_snaps/release.md @@ -0,0 +1,67 @@ +# release: returns the object back to the pool, and it can be recycled + + Code + poolCheckout(pool) + Condition + Error in `poolCheckout()`: + ! Maximum number of objects in pool has been reached + +# release: throws if object was already released + + Code + poolReturn(obj) + Condition + Error in `poolReturn()`: + ! This object was already returned to the pool. + +# release: throws if object is not valid + + Code + poolReturn(obj) + Condition + Error in `poolReturn()`: + ! Invalid object. + +# release: warns if onPassivate fails + + Code + poolReturn(obj) + Condition + Error in `poolReturn()`: + ! Object could not be returned back to the pool. + * It was destroyed instead + Caused by error in `onPassivate()`: + ! Passivation failed... + +# release: is allowed after the pool is closed + + Code + poolClose(pool) + Output + You still have checked out objects. + Use `poolReturn()` them to the pool so they can be destroyed. + +--- + + Code + poolClose(pool) + Condition + Error in `pool$close()`: + ! The pool was already closed. + +# release: warns if object can't be returned + + Code + pool <- poolCreate(function() 1) + obj <- poolCheckout(pool) + rm(obj) + . <- gc() + Output + Checked-out object deleted before being returned. + Make sure to `poolReturn()` all objects retrieved with `poolCheckout().` + Code + poolClose(pool) + Output + You still have checked out objects. + Use `poolReturn()` them to the pool so they can be destroyed. + diff --git a/tests/testthat/test-create-destroy.R b/tests/testthat/test-create-destroy.R index 606d37c..fe76ca8 100644 --- a/tests/testthat/test-create-destroy.R +++ b/tests/testthat/test-create-destroy.R @@ -1,62 +1,31 @@ source("utils.R") -describe("createObject", { - - it("throws if `factory` throws or returns NULL", { - expect_error(poolCreate(MockPooledObj), - "attempt to apply non-function") - expect_error(poolCreate(function(x) NULL), - "Object creation was not successful.") +test_that("createObject throws if `factory` throws or returns NULL", { + expect_snapshot(error = TRUE, { + poolCreate(MockPooledObj) + poolCreate(function(x) NULL) }) }) -describe("destroyObject", { - - pool <- poolCreate(MockPooledObj$new, - minSize = 1, maxSize = 3, idleTimeout = 0) - - it("throws if onDestroy fails", { - checkCounts(pool, free = 1, taken = 0) - failOnDestroy <<- TRUE +test_that("useful warning if onDestroy fails", { + pool <- poolCreate(MockPooledObj$new, idleTimeout = 0) - a <- poolCheckout(pool) - b <- poolCheckout(pool) - checkCounts(pool, free = 0, taken = 2) + checkCounts(pool, free = 1, taken = 0) + failOnDestroy <<- TRUE - ## since we're over the minSize, once we return `b` to - ## the pool, it will be destroyed immediately (since - ## we set `idleTimeout = 0`) - # - # Previously, the expect_error() below was a expect_warning(), but a - # change in later 1.0.0 altered the way that warnings are handled; they no - # longer pass up through run_now(). A future version of later may change - # that back to the original behavior. The workaround is to convert the - # warning to an error and look for the error. - op <- options(warn = 2) - on.exit(options(op), add = TRUE) - expect_error({ - poolReturn(b) - later::run_now() # this is needed so that the scheduler runs NOW - }, - regexp = paste0( - "Object of class MockPooledObj could not be ", - "destroyed properly, but was successfully removed ", - "from pool." - ), - # The class seems redundant, but is necessary for this test to not throw - # an unnecessary error with later<1.0.0. It can be removed in the future - # after later 1.0.0 has been released. - class = "error" - ) + a <- poolCheckout(pool) + b <- poolCheckout(pool) - checkCounts(pool, free = 0, taken = 1) - failOnDestroy <<- FALSE - - ## cleanup: return `a` - poolReturn(a) - checkCounts(pool, free = 1, taken = 0) + # since we're over minSize, returning `b` destroy it + expect_snapshot({ + poolReturn(b) + later::run_now() }) + checkCounts(pool, free = 0, taken = 1) + failOnDestroy <<- FALSE + + poolReturn(a) poolClose(pool) gc() }) diff --git a/tests/testthat/test-fetch.R b/tests/testthat/test-fetch.R index f5238ef..e9792b8 100644 --- a/tests/testthat/test-fetch.R +++ b/tests/testthat/test-fetch.R @@ -1,6 +1,7 @@ source("utils.R") describe("fetch", { + local_reproducible_output() pool <- poolCreate(MockPooledObj$new, minSize = 1, maxSize = 3, validationInterval = 1) @@ -9,11 +10,7 @@ describe("fetch", { checkCounts(pool, free = 1, taken = 0) failOnActivate <<- TRUE - expect_error( - expect_warning(obj <- poolCheckout(pool), - paste("It wasn't possible to activate and/or validate", - "the object. Trying again with a new object.")), - "Object does not appear to be valid.") + expect_snapshot(poolCheckout(pool), error = TRUE) checkCounts(pool, free = 0, taken = 0) failOnActivate <<- FALSE }) @@ -21,11 +18,7 @@ describe("fetch", { it("throws if onValidate fails", { checkCounts(pool, free = 0, taken = 0) failOnValidate <<- TRUE - expect_error( - expect_warning(poolCheckout(pool), - paste("It wasn't possible to activate and/or validate", - "the object. Trying again with a new object.")), - "Object does not appear to be valid.") + expect_snapshot(poolCheckout(pool), error = TRUE) checkCounts(pool, free = 0, taken = 0) failOnValidate <<- FALSE }) @@ -113,9 +106,7 @@ describe("fetch", { Sys.sleep(pool$validationInterval + 1) attr(badObject, "bad") <- TRUE - expect_warning(obj <- get_private(pool)$checkValid(badObject), - paste("It wasn't possible to activate and/or validate", - "the object. Trying again with a new object.")) + expect_snapshot(obj <- get_private(pool)$checkValid(badObject)) Sys.sleep(pool$validationInterval + 1) ## check that the new object is valid @@ -128,11 +119,8 @@ describe("fetch", { ## cannot validate bad object, so creates new one and tries again ## new object's activation and validation also fails: throw failOnValidate <<- TRUE - expect_error( - expect_warning(get_private(pool)$checkValid(obj), - paste("It wasn't possible to activate and/or validate", - "the object. Trying again with a new object.")), - "Object does not appear to be valid.") + + expect_snapshot(get_private(pool)$checkValid(obj), error = TRUE) failOnValidate <<- FALSE ## since we couldn't validate the object the first or the second @@ -140,16 +128,13 @@ describe("fetch", { ## in the pool checkCounts(pool, free = 0, taken = 0) }) + poolClose(pool) it("throws if the pool was closed", { - checkCounts(pool, free = 0, taken = 0) - obj <- poolCheckout(pool) - poolReturn(obj) - - checkCounts(pool, free = 1, taken = 0) + pool <- poolCreate(function() 1) poolClose(pool) - checkCounts(pool, free = 0, taken = 0) - expect_error(poolCheckout(pool), - "This pool is no longer valid. Cannot fetch new objects.") + + expect_snapshot(poolCheckout(pool), error = TRUE) }) + }) diff --git a/tests/testthat/test-pool.R b/tests/testthat/test-pool.R index 9bbaee8..bdf0774 100644 --- a/tests/testthat/test-pool.R +++ b/tests/testthat/test-pool.R @@ -1,6 +1,7 @@ source("utils.R") describe("pool", { + local_reproducible_output() describe("basic mechanics", { pool <- poolCreate(MockPooledObj$new, @@ -45,13 +46,16 @@ describe("pool", { }) it("enforces maxSize", { + pool <- poolCreate(function() 1, maxSize = 3) + a <- poolCheckout(pool) b <- poolCheckout(pool) c <- poolCheckout(pool) - expect_error(poolCheckout(pool), - "Maximum number of objects in pool has been reached") + expect_snapshot(poolCheckout(pool), error = TRUE) objs <- list(a, b, c) lapply(objs, poolReturn) + + poolClose(pool) }) poolClose(pool) diff --git a/tests/testthat/test-release.R b/tests/testthat/test-release.R index 7ef2a75..6953862 100644 --- a/tests/testthat/test-release.R +++ b/tests/testthat/test-release.R @@ -1,6 +1,7 @@ source("utils.R") describe("release", { + local_reproducible_output() pool <- poolCreate(MockPooledObj$new, minSize = 1, maxSize = 3, idleTimeout = 0) @@ -12,9 +13,7 @@ describe("release", { obj3 <- poolCheckout(pool) checkCounts(pool, free = 0, taken = 3) - expect_error(obj4 <- poolCheckout(pool), - paste("Maximum number of objects in pool has been reached") - ) + expect_snapshot(poolCheckout(pool), error = TRUE) checkCounts(pool, free = 0, taken = 3) poolReturn(obj3) @@ -31,23 +30,20 @@ describe("release", { checkCounts(pool, free = 1, taken = 0) obj <- poolCheckout(pool) poolReturn(obj) - expect_error(poolReturn(obj), - "This object was already returned to the pool.") + expect_snapshot(poolReturn(obj), error = TRUE) checkCounts(pool, free = 1, taken = 0) }) it("throws if object is not valid", { obj <- "a" - expect_error(poolReturn(obj), "Invalid object.") + expect_snapshot(poolReturn(obj), error = TRUE) }) it("warns if onPassivate fails", { checkCounts(pool, free = 1, taken = 0) obj <- poolCheckout(pool) failOnPassivate <<- TRUE - expect_error(poolReturn(obj), - paste("Object could not be returned back to the pool.", - "It was destroyed instead.")) + expect_snapshot(poolReturn(obj), error = TRUE) failOnPassivate <<- FALSE checkCounts(pool, free = 0, taken = 0) }) @@ -56,15 +52,22 @@ describe("release", { checkCounts(pool, free = 0, taken = 0) obj <- poolCheckout(pool) checkCounts(pool, free = 0, taken = 1) - expect_warning(poolClose(pool), - "You still have checked out objects.") + expect_snapshot(poolClose(pool)) checkCounts(pool, free = 0, taken = 1) poolReturn(obj) checkCounts(pool, free = 0, taken = 0) - expect_error(poolClose(pool), - "The pool was already closed.") + expect_snapshot(poolClose(pool), error = TRUE) }) -}) + it("warns if object can't be returned", { + expect_snapshot({ + pool <- poolCreate(function() 1) + obj <- poolCheckout(pool) + rm(obj) + . <- gc() + poolClose(pool) + }) + }) +})