Closes #55 (bug: Duplicated error dump files in stacked tryCatchLog c…

…alls)
aryoda · Apr 20, 2020 · c9501e8 · c9501e8 · lintr-bot · Apr 20, 2020
1 parent c3638bb
commit c9501e8
Show file tree

Hide file tree

Showing 7 changed files with 116 additions and 144 deletions.
diff --git a/NEWS.md b/NEWS.md
@@ -5,13 +5,15 @@ For the conventions for files NEWS and ChangeLog in the GNU project see
 https://www.gnu.org/prep/standards/standards.html#Documentation
 -->
 
-## Version 1.1.8 (April xx, 2020)
+## Version 1.1.8 (April 20, 2020)
 
 * Implemented feature requests #14 and #45: Support logging of all conditions (incl. user-defined conditions).
   * Interrupt conditions are logged with the message "User-requested interrupt"
     even though R does not deliver a message.  (incl. user-defined and interrupt)
   * https://github.com/aryoda/tryCatchLog/issues/14
   * https://github.com/aryoda/tryCatchLog/issues/45
+* Fixed bug #55: Duplicated error dump files in stacked tryCatchLog calls
+  * https://github.com/aryoda/tryCatchLog/issues/55
 
 ## Version 1.1.7 (April 6, 2020)
 
@@ -32,7 +34,7 @@ https://www.gnu.org/prep/standards/standards.html#Documentation
         argument to make it more visible. The signature is still compatible since it follows
         the `...` argument which requires all subsequent arguments to be named in calls.
 * Fixed bug: `last.tryCatchLog.result()` has sometimes not been reset in case of an internal error
-  so that the result of the previous `tryCatchLog` or `tryLog` call was returned.
+  so that the result of the previous `tryCatchLog` or `tryLog` call was returned (no issue number).
 
 
 

diff --git a/R/is_already_logged.R b/R/is_already_logged.R
diff --git a/R/is_duplicated_log_entry.R b/R/is_duplicated_log_entry.R
@@ -19,9 +19,6 @@
 
 #' Check if a new log entry would be a duplicate of on an already existing log entry
 #'
-#' DEPRECATED due to a required signature change to fix issue #55:
-#'            https://github.com/aryoda/tryCatchLog/issues/55
-#'
 #' The \code{log.entry} is checked against the existing log entries from
 #' \code{\link{last.tryCatchLog.result}} using the following columns:
 #'         \enumerate{
@@ -40,8 +37,6 @@
 #'          \code{\link{build.log.entry}}
 is.duplicated.log.entry <- function(log.entry) {
 
-  # warning("DEPRECATED function due to a required signature change to fix issue #55")
-
   if (is.null(log.entry))
     return(TRUE)    # an empty entry is useless - treat it like a duplicate
 

diff --git a/R/tryCatchLog.R b/R/tryCatchLog.R
@@ -229,30 +229,6 @@ tryCatchLog <- function(expr,
 
 
 
-    # Save dump to allow post mortem debugging?
-    if (write.error.dump.file == TRUE & severity == "ERROR") {
-
-      # See"?dump.frames" on how to load and debug the dump in a later interactive R session!
-      # See https://stackoverflow.com/questions/40421552/r-how-make-dump-frames-include-all-variables-for-later-post-mortem-debugging/40431711#40431711
-      # why you should avoid dump.frames(to.file = TRUE)...
-      # https://bugs.r-project.org/bugzilla/show_bug.cgi?id=17116
-      # An enhanced version of "dump.frames" was released in spring 2017 but does still not fulfill the requirements of tryCatchLog:
-      # dump.frames(dumpto = dump.file.name, to.file = TRUE, include.GlobalEnv = TRUE)  # test it yourself!
-      # See ?strptime for the available formatting codes...
-      #
-      # Creates a (hopefully) unique dump file name even in case of multiple parallel processes
-      # or multiple sequential errors in the same R process.
-      # Fixes issue #39 by appending fractional seconds (milliseconds) and the process id (PID)
-      # https://github.com/aryoda/tryCatchLog/issues/39
-      # Example dump file name: dump_2019-03-13_at_15-39-33.086_PID_15270.rda
-      dump.file.name  <- paste0(format(timestamp, format = "dump_%Y-%m-%d_at_%H-%M-%OS3"), "_PID_", Sys.getpid(), ".rda")  # %OS3 (= seconds incl. milliseconds)
-      dir.create(path = write.error.dump.folder, recursive = T, showWarnings = F)
-      utils::dump.frames()
-      save.image(file = file.path(write.error.dump.folder, dump.file.name))  # an existing file would be overwritten silently :-()
-    }
-
-
-
     log.entry <- build.log.entry(timestamp, severity, log.message, execution.context.msg, call.stack, dump.file.name, omit.call.stack.items = 1)
 
 
@@ -264,6 +240,31 @@ tryCatchLog <- function(expr,
     # if (!is.already.logged(log.message, call.stack)) {
     if (!is.duplicated.log.entry(log.entry)) {
 
+      # Save dump to allow post mortem debugging?
+      if (write.error.dump.file == TRUE & severity == "ERROR") {
+
+        # See"?dump.frames" on how to load and debug the dump in a later interactive R session!
+        # See https://stackoverflow.com/questions/40421552/r-how-make-dump-frames-include-all-variables-for-later-post-mortem-debugging/40431711#40431711
+        # why you should avoid dump.frames(to.file = TRUE)...
+        # https://bugs.r-project.org/bugzilla/show_bug.cgi?id=17116
+        # An enhanced version of "dump.frames" was released in spring 2017 but does still not fulfill the requirements of tryCatchLog:
+        # dump.frames(dumpto = dump.file.name, to.file = TRUE, include.GlobalEnv = TRUE)  # test it yourself!
+        # See ?strptime for the available formatting codes...
+        #
+        # Creates a (hopefully) unique dump file name even in case of multiple parallel processes
+        # or multiple sequential errors in the same R process.
+        # Fixes issue #39 by appending fractional seconds (milliseconds) and the process id (PID)
+        # https://github.com/aryoda/tryCatchLog/issues/39
+        # Example dump file name: dump_2019-03-13_at_15-39-33.086_PID_15270.rda
+        dump.file.name  <- paste0(format(timestamp, format = "dump_%Y-%m-%d_at_%H-%M-%OS3"), "_PID_", Sys.getpid(), ".rda")  # %OS3 (= seconds incl. milliseconds)
+        dir.create(path = write.error.dump.folder, recursive = T, showWarnings = F)
+        utils::dump.frames()
+        save.image(file = file.path(write.error.dump.folder, dump.file.name))  # an existing file would be overwritten silently :-()
+        log.entry$dump.file.name = dump.file.name
+      }
+
+
+
       log.msg <-   build.log.output(log.entry,
                                     include.full.call.stack    = include.full.call.stack,
                                     include.compact.call.stack = include.compact.call.stack)

diff --git a/man/is.already.logged.Rd b/man/is.already.logged.Rd
diff --git a/man/is.duplicated.log.entry.Rd b/man/is.duplicated.log.entry.Rd
diff --git a/tests/testthat/test_dump_files.R b/tests/testthat/test_dump_files.R
@@ -4,6 +4,7 @@
 # Clean it up at the beginning of a test!
 
 library(testthat)
+library(tryCatchLog)
 
 
 
@@ -51,9 +52,6 @@ source("disable_logging_output.R")
 
 # unit tests ------------------------------------------------------------------------------------------------------
 
-# context("dump.to.file")  # confusing
-
-
 test_that("no dump file is created without an error", {
   tryCatchLog(TRUE, write.error.dump.file = TRUE)
   expect_equal(number.of.dump.files(), 0)
@@ -71,42 +69,42 @@ test_that("no dump file is created for a warning", {
 
 
 test_that("no dump file is created with an error but disabled write.error.dump.file parameter", {
-            tryCatchLog(
-              log("a"),
-              error = function(e) {
-              },
-              write.error.dump.file = FALSE
-            )
-            expect_equal(number.of.dump.files(), 0)
+  tryCatchLog(
+    log("a"),
+    error = function(e) {
+    },
+    write.error.dump.file = FALSE
+  )
+  expect_equal(number.of.dump.files(), 0)
 
-            clean.up.dump.files()
+  clean.up.dump.files()
 
-            log <- last.tryCatchLog.result()
-            expect_equal(log$dump.file.name, "", info = "no dump file contained in log")
-          })
+  log <- last.tryCatchLog.result()
+  expect_equal(log$dump.file.name, "", info = "no dump file contained in log")
+})
 
 
 
 test_that("dump file is created with an error and write.error.dump.file parameter enabled", {
-            tryCatchLog(
-              log("a"),
-              error = function(e) {
-              },
-              write.error.dump.file = TRUE
-            )
+  tryCatchLog(
+    log("a"),
+    error = function(e) {
+    },
+    write.error.dump.file = TRUE
+  )
 
-            expect_equal(number.of.dump.files(), 1)
+  expect_equal(number.of.dump.files(), 1)
 
-            log <- last.tryCatchLog.result()
+  log <- last.tryCatchLog.result()
 
-            # Check for correct logging of dump file name
-            expect_true(!is.na(log$dump.file.name))
-            expect_gt(nchar(log$dump.file.name), 0)
-            expect_true(file.exists(log$dump.file.name), info = "correct dump file contained in log")
-            # print(log$dump.file.name)
+  # Check for correct logging of dump file name
+  expect_true(!is.na(log$dump.file.name))
+  expect_gt(nchar(log$dump.file.name), 0)
+  expect_true(file.exists(log$dump.file.name), info = "correct dump file contained in log")
+  # print(log$dump.file.name)
 
-            clean.up.dump.files()
-          })
+  clean.up.dump.files()
+})
 
 
 
@@ -184,6 +182,8 @@ test_that("dump file is created (error and dump default enabled)", {
 
 options("tryCatchLog.write.error.dump.folder" = "temp_subfolder")
 
+
+
 test_that("dump file is created in a specifc folder (error and dump default enabled)", {
   tryCatchLog(
     log("a"),
@@ -214,10 +214,67 @@ test_that("dump files are not overwritten due to duplicated file names (non-dete
 
 
 
+options("tryCatchLog.write.error.dump.folder" = NULL)
+# getOption("tryCatchLog.write.error.dump.folder", ".")
+
+test_that("exactly one dump file is created in stacked tryCatchLog calls with handlers", {
+
+  # inner and outer error handler
+  tryCatchLog(
+    tryCatchLog(
+      log("a"),
+      error = function(e) {
+      },
+      write.error.dump.file = TRUE),
+    error = function(e) {
+    },
+    write.error.dump.file = TRUE
+  )
+
+  expect_equal(number.of.dump.files(), 1)
+
+  log <- last.tryCatchLog.result()
+
+  # Check for correct logging of dump file name
+  expect_true(!is.na(log$dump.file.name))
+  expect_gt(nchar(log$dump.file.name), 0)
+  expect_true(file.exists(log$dump.file.name), info = "correct dump file contained in log")
+  # print(log$dump.file.name)
+
+  clean.up.dump.files()
+})
+
+
+
+test_that("exactly one dump file is created in stacked tryCatchLog calls without handlers", {
+
+  # inner and outer error handler
+  expect_error(tryCatchLog(
+    tryCatchLog(
+      log("a"),
+      write.error.dump.file = TRUE),
+    write.error.dump.file = TRUE
+  ))
+
+  expect_equal(number.of.dump.files(), 1)
+
+  log <- last.tryCatchLog.result()
+
+  # Check for correct logging of dump file name
+  expect_true(!is.na(log$dump.file.name))
+  expect_gt(nchar(log$dump.file.name), 0)
+  expect_true(file.exists(log$dump.file.name), info = "correct dump file contained in log")
+  # print(log$dump.file.name)
+
+  clean.up.dump.files()
+})
+
+
+
 # Cleanup ----------------------------------------------------------------------------
 
 clean.up.dump.files()
 clean.up.dump.files("temp_subfolder")
 unlink("temp_subfolder", recursive = TRUE)  # with the default value "FALSE" the folder is NOT deleted (see help)
 
-options("tryCatchLog.write.error.dump.file" = ".")  # just to be sure :-)
+options("tryCatchLog.write.error.dump.file" = NULL)   #  ".")  # just to be sure :-)