How to implement a trace function for table to functions?

Question

I have a table like this

local ftable = {
  getPinId = app.getPinId
}

ftable is passed to another function which exports it as a RPC interface. This works but now I want to add function call tracing to a log file.

The simple approach is

local ftable = {
  getPinId = function(...) print("getPinId") app.getPinId(...) end
}

But, this is not particularly nice. I'd like to put something like:

local trace = function(func, ...)
   return function(...) print(func) func(...) end
end

local ftable = {
  getPinId = trace(app.getPinId)
}

But this doesn't produce quite the desired result. The parameters are not being passed through.

One other option is to use a metatable like this:

local ftable = {}
setmetatable(ftable, { 
  __index = function(_, k) 
  printf("Call: app.%s\n", k) return app[k] end 
})

Which works. But I'd also like to be able to print the parameters that are passed if possible.

Any suggestions? I'm exclusively using luajit if that makes any difference.

Answer 1

Wrapping a function call is easy in Lua:

local function wrap( f )
  local function after( ... )
    -- code to execute *after* function call to f
    print( "return values:", ... )
    return ...
  end
  return function( ... )
    -- code to execute *before* function call to f
    print( "arguments:", ... )
    return after( f( ... ) )
  end
end


local function f( a, b, c )
  return a+b, c-a
end

local f_wrapped = wrap( f )
f_wrapped( 1, 2, 3 )

Output is:

arguments:  1   2   3
return values:  3   2

One problem for logging/tracing is that Lua values (including functions) don't have names themselves. The debug library tries to find suitable names for functions by inspecting how they are called or where they are stored, but if you want to make sure, you'll have to supply a name yourself. However, if your functions are stored in (nested) tables (as indicated in a comment), you could write a function that iterates the nested tables, and wraps all functions it finds using the table keys as names:

local function trace( name, value )
  local t = type( value )
  if t == "function" then -- do the wrapping
    local function after( ... )
      print( name.." returns:", ... )
      return ...
    end
    return function( ... )
      print( "calling "..name..":", ... )
      return after( value( ... ) )
    end
  elseif t == "table" then -- recurse into subtables
    local copy = nil
    for k,v in pairs( value ) do
      local nv = trace( name.."."..tostring( k ), v )
      if nv ~= v then
        copy = copy or setmetatable( {}, { __index = value } )
        copy[ k ] = nv
      end
    end
    return copy or value
  else -- other values are ignored (returned as is)
    return value
  end
end


local ftable = {
  getPinId = function( ... ) return "x", ... end,
  nested = {
    getPinId = function( ... ) return "y", ... end
  }
}

local ftableTraced = trace( "ftable", ftable )
ftableTraced.getPinId( 1, 2, 3 )
ftableTraced.nested.getPinId( 2, 3, 4 )

Output is:

calling ftable.getPinId:    1   2   3
ftable.getPinId returns:    x   1   2   3
calling ftable.nested.getPinId: 2   3   4
ftable.nested.getPinId returns: y   2   3   4

Some things to be aware of:

1. Table keys can be arbitrary Lua values, not just short strings entirely consisting of printable characters.
2. Tables can contain cyclic references. If they do, the naive implementation above will die with a stack overflow.