This code was still a little painful, because I had to change the name of each the function inside each message. Ideally, the message should just know what function it was inside. To get this, some examination of the call stack by sys.call was required.

This worked, and was fast and was relatively easy to set up, since it is the same code that is being added to each function, making tracking multiple functions easy, as shown in the more complicated (and convoluted) example below.

It still bugged me though. The fact that analytical code was being polluted with logging code didn’t seem semantically right. What I really wanted was a way to track these functions without inserting any code into them at all. An hour or so of digging about in the manuals and I discovered that I didn’t want to track the functions. In R parlance, I wanted to trace them. And inevitably, there was a trace function to do just that. trace has two different implementations; which version you get depends upon whether more than one argument is passed.