Automatically Adding Enter/Exit Function Logs to a Project

Automatically adding Enter/Exit Function Logs to a Project

Besides the usual debugger and aspect-oriented programming techniques, you can also inject your own instrumentation functions using gcc's -finstrument-functions command line options. You'll have to implement your own __cyg_profile_func_enter() and __cyg_profile_func_exit() functions (declare these as extern "C" in C++).

They provide a means to track what function was called from where. However, the interface is a bit difficult to use since the address of the function being called and its call site are passed instead of a function name, for example. You could log the addresses, and then pull the corresponding names from the symbol table using something like objdump --syms or nm, assuming of course the symbols haven't been stripped from the binaries in question.

It may just be easier to use gdb. YMMV. :)

Automatic Entry Exit trace in C

C does not support any form of introspection or doing stuff automatically through magic in the runtime or on the virtual machine; there is no virtual machine, and the runtime support is basically just libraries of "dead" code that provide standard functionality.

And as Subtwo pointed out, if you want to do something (like log entry/exit), it will have to be done and thus take time. You can't just "hide" that penalty, there is very little overhead to put it in.

A standard profiler might give you some insight, by sampling your program statistically to see which functions execute, but that will not give you the call order, just random locations where your program was executing code at the time it was sampled.

You could perhaps turn to some preprocessor trickery, this is a common way to do "boilerplate" stuff like logging, by for instance defining some macros that you then put at the entry/exit points of each function. Still, you'd have to remember including the macros, and any performance penalty from doing the logging will of course be present.

Script to insert logging into every function in a project?

Had something similar for adding profiling code using Macros in VS, here's the code
(this also groups everything under a single "undo" command and lists all of the changes in its own output window)

Imports System
Imports EnvDTE
Imports EnvDTE80
Imports System.Diagnostics

Public Module Module1

    Function GetOutputWindowPane(ByVal Name As String, Optional ByVal show As Boolean = True) As OutputWindowPane
        Dim window As Window
        Dim outputWindow As OutputWindow
        Dim outputWindowPane As OutputWindowPane

        window = DTE.Windows.Item(EnvDTE.Constants.vsWindowKindOutput)
        If show Then window.Visible = True
        outputWindow = window.Object
        Try
            outputWindowPane = outputWindow.OutputWindowPanes.Item(Name)
        Catch e As System.Exception
            outputWindowPane = outputWindow.OutputWindowPanes.Add(Name)
        End Try
        outputWindowPane.Activate()
        Return outputWindowPane
    End Function

    Const ToInsert As String = "/* Inserted text :D */"

    Sub AddProfilingToFunction(ByVal func As CodeFunction2)
        Dim editPoint As EditPoint2 = func.StartPoint.CreateEditPoint()
        While editPoint.GetText(1) <> "{"
            editPoint.CharRight()
        End While

        editPoint.CharRight()
        editPoint.InsertNewLine(1)

        Dim insertStartLine As Integer = editPoint.Line
        Dim insertStartChar As Integer = editPoint.LineCharOffset
        editPoint.Insert(ToInsert)

        GetOutputWindowPane("Macro Inserted Code").OutputString( _
            editPoint.Parent.Parent.FullName & _
            "(" & insertStartLine & "," & insertStartChar & _
            ") : Inserted Code """ & ToInsert & """" & vbCrLf)
    End Sub

    Sub AddProfilingToProject(ByVal proj As Project)
        If Not proj.CodeModel() Is Nothing Then
            Dim EventTitle As String = "Add Profiling to project '" & proj.Name & "'"
            GetOutputWindowPane("Macro Inserted Code").OutputString("Add Profiling to project '" & proj.Name & "'" & vbCrLf)
            DTE.UndoContext.Open(EventTitle)
            Try
                Dim allNames As String = ""
                For i As Integer = 1 To proj.CodeModel().CodeElements.Count()
                    If proj.CodeModel().CodeElements.Item(i).Kind = vsCMElement.vsCMElementFunction Then
                        AddProfilingToFunction(proj.CodeModel().CodeElements.Item(i))
                    End If
                Next
            Finally
                DTE.UndoContext.Close()
            End Try
            GetOutputWindowPane("Macro Inserted Code").OutputString(vbCrLf)
        End If
    End Sub

    Sub AddProfilingToSolution()
        GetOutputWindowPane("Macro Inserted Code").Clear()
        If Not DTE.Solution Is Nothing And DTE.Solution.IsOpen() Then
            For i As Integer = 1 To DTE.Solution.Projects.Count()
                AddProfilingToProject(DTE.Solution.Projects.Item(i))
            Next
        End If
    End Sub

End Module

P.S
Remember to change the "Const ToInsert As String = ..." to the code you actually want to be inserted

How to automatically log the entry/exit of methods in Java?

I suggest the use of Aspect Oriented Programming.

For example, using the AspectJ compiler (which can be integrated to Eclipse, Emacs and others IDEs), you can create a piece of code like this one:

aspect AspectExample {
    before() : execution(* Point.*(..))
    {
         logger.entering(thisJoinPointStaticPart.getSignature().getName(), thisJoinPointStaticPart.getSignature().getDeclaringType()   );

    }

    after() : execution(* Point.*(..))
    {
         logger.exiting(thisJoinPointStaticPart.getSignature().getName() , thisJoinPointStaticPart.getSignature().getDeclaringType()  );

    }
}

This aspect adds a logging code after and before the execution of all methods in the class "Point".

Autogenerating a function wrapper in C

I had to give up from installing wrapper on function declaration, the solution was to install the wrappers on function call using compound statements. Bellow the two macros I created to do that, one deals with calls returning void, other with any call that returns a value:

#define PROFILE_VOID(call) \
({ \
  hal_time_t stop, start; \
  hal_getTime(&start); \
  call; \
  hal_getTime(&stop); \
  __PROFILE_PRINT(call, hal_secondsElapsed_d(&stop, &start)); \
})

#define PROFILE(call) \
({ \
  typeof(call) __ret; \
  hal_time_t stop, start; \
  __profile_nested_cnt++; \
  hal_getTime(&start); \
  __ret = call; \
  hal_getTime(&stop); \
  __profile_nested_cnt--; \
  __PROFILE_PRINT(call, hal_secondsElapsed_d(&stop, &start)); \
  __ret; \
})

Example of use:

PROFILE_VOID(func_returning_void(arg, arg2)); //Void func
PROFILE(other_funcs());  // Any non void func
PROFILE(x = func(x, y, z));  //Any statement
x = PROFILE(func(x, y, z));  //Same as previous
if (PROFILE(func()) == 0) { } //Inside conditionals
if (PROFILE(func() == 0)) { } //Same as previous

---

Related Topics