Oh (de)bugger! Part II

It’s Friday night, and I recently discovered that adding a dash of Cointreau somewhat enhances a gin and tonic.  Consequently, I’m drunk-blogging.  Will try not to make too many tpyos.

In the first part of this series, I discussed some standard debugging techniques, like the use of the browser function.  One of the limitations of browser is that it isn’t much help if the problem is somewhere higher up the call-stack.  That is, the case when you passed a dodgy argument to another function, which maybe passed it on to something else before your code fell over.

If you have an error, but you don’t know where it is, then a helpful thing to see is your call stack, and the variables that you’ve put in it.  The function I’m going to show you uses sys.calls to retrieve the call stack, and sys.frames to retrieve the environment for each function you called.  Next it calls ls.str in each of those environments to tell you what variables you’ve created.  Finally, there are some methods to print your output more clearly.  After all, the whole point of this function is to give you quick insight into what you’ve just done.

When I was trying to think of a suitable name for this function, I toyed with variations on the word “stack”.  Eventually, I figured that it should be named for the word most commonly used when things go wrong.  And so, I present to you, the bugger function.

bugger <- function(...) { # ... contains arguments passed to ls.str.  See that function for a description. +++stack_length <- sys.nframe() +++call_stack <- sys.calls()[-stack_length] # -stack_length is so we don't include this function +++frames <- sys.frames()[-stack_length] +++ls_stack <- lapply(frames, function(e) ls.str(envir = e, ...)) +++call_names <- make.names(lapply(call_stack, ++++++function(cl) as.character(cl)[1]), unique = TRUE) +++names(call_stack) <- call_names +++names(ls_stack) <- call_names +++class(call_stack) <- "call_stack" +++class(ls_stack) <- "ls_stack" +++list(call_stack = call_stack, ls_stack = ls_stack) }

The call to make.names is there to ensure that each items in call_stack and ls_stack have a unique name, and thus can be referenced more easily.   To finish, these two components get S3-style overloads of the print function.

print.call_stack <- function(x) { +++n <- length(x) +++if(n < 1) cat("Call stack is emptyn") +++calls <- sapply(x, function(x) as.character(as.expression(x))) +++cat(paste(seq_len(n), calls, sep = ": "), sep = "n") +++invisible(x) }

print.ls_stack <- function(x, ...) { +++n <- length(x) +++if(n < 1) cat("Call stack is emptyn") +++titles <- paste(seq_len(n), names(x), sep = ": ") +++for(i in seq_len(n)) +++{ ++++++cat(titles[i], "n") ++++++noquote(print(x[[i]], ...)) ++++++cat("n") +++} +++invisible(x) }

And finally, here’s an example to put the code to use

bar <- function(xx, ...) { +++bugger() }

foo <- function(x, y, z) { +++another_variable <- 999 +++bar(x, y, letters[1:5]) }

foo(1:10, "monkey", list(runif(3), zzz = "zzz"))

This yields the result
$call_stack 1: foo(1:10, "monkey", list(runif(3), zzz = "zzz")) 2: bar(x, y, letters[1:5])

$ls_stack 1: foo another_variable : num 999 x : int [1:10] 1 2 3 4 5 6 7 8 9 10 y : chr "monkey" z : List of 2 +$ : num [1:3] 0.154 0.974 0.189 +$ zzz: chr "zzz"2: bar xx : int [1:10] 1 2 3 4 5 6 7 8 9 10

One thing to note is that ls.str doesn’t pick up the ... arguments.  It is possible to retrieve the call to those dots from each environment, but it isn’t always possible to evaluate them.  Playing with R’s evaluation model in this way is deep magic, so accessing them involves excessive use of substitute and eval.  I’m going to postpone talking about them for an occasion that didn’t involve gin and cointreau.