Function Tracing

Function tracing

This page describes how to use Logme function tracing macros for logging function entry, function exit, arguments, return values, execution time and channel selection.

The examples below are based on the function tracing article and use the same API patterns.

---

Basic profiling macros

Function tracing in logme is implemented through the LogmeP family of macros.

Naming rules:

• V means the function is traced without logging a return value
• level suffixes:
  • D — Debug
  • I — Info
  • W — Warning
  • E — Error
  • C — Critical

If no level is specified, Info is used by default.

To log function entry and exit without parameters or return value, use:

LogmePV(); // or LogmePVI()

---

Example: basic function tracing

#include <thread>
#include <chrono>

#include <Logme/Logme.h>

int MyProc(int i, const char* name)
{
  LogmePV();

  std::this_thread::sleep_for(std::chrono::milliseconds(100));
  return i + 1;
}

int main()
{
  MyProc(123, "abc");
  return 0;
}

Typical output:

>> MyProc()
<< MyProc()

---

Measuring execution time

To include execution time in the output, enable the Duration flag on the logging channel:

int main()
{
  auto ch = Logme::Instance->GetDefaultChannelPtr();
  auto flags = ch->GetFlags();
  flags.Duration = true;
  ch->SetFlags(flags);

  MyProc(123, "abc");
  return 0;
}

Typical output:

>> MyProc()
<< MyProc() [102ms]

---

Logging return values

To log the return value, use a macro without the V suffix and pass a variable that stores the result:

int MyProc(int i, const char* name)
{
  int ret{};
  LogmePW(ret);

  ret = i + 1;

  std::this_thread::sleep_for(std::chrono::milliseconds(100));
  return ret;
}

Typical output:

>> MyProc()
<< MyProc() 124 [102ms]

---

Logging function arguments

To include function arguments in the log, pass them using helper macros.

Values only

int MyProc(int i, const char* name)
{
  LogmePV(ARGS(i, name));

  std::this_thread::sleep_for(std::chrono::milliseconds(100));
  return i + 1;
}

Typical output:

>> MyProc() 123, abc
<< MyProc()

Names and values

int MyProc(int i, const char* name)
{
  LogmePV(ARGS2(i, name));

  std::this_thread::sleep_for(std::chrono::milliseconds(100));
  return i + 1;
}

Typical output:

>> MyProc() i=123, name=abc
<< MyProc()

Macros such as ARGS1, ARGS2, and similar variants control how many parameters are passed and allow logme to include both values and names.

---

Custom printers for complex types

For standard types, logme already provides built-in formatting. For user-defined types, define a formatter:

struct Point
{
  int X;
  int Y;
};

template<> std::string FormatValue<Point>(const Point& value)
{
  return "Point(" + std::to_string(value.X) + ", " + std::to_string(value.Y) + ")";
}
static Point MakePoint(int x, int y)
{
  Point r{ x, y };
  LogmeP(r);

  return r;
}

This allows logme to print a meaningful representation of the custom type.

---

Selecting a logging channel

All previous examples use the default logging channel. To use a custom channel:

Logme::ID CHT{ "test" };

int MyProc(int i, const char* name)
{
  int ret{};
  LogmePI(ret, CHT, ARGS2(i, name));

  ret = i + 1;
  std::this_thread::sleep_for(std::chrono::milliseconds(100));

  return ret;
}

int main()
{
  auto ch = Logme::Instance->CreateChannel(CHT);
  ch->AddLink(::CH);
  MyProc(123, "abc");
  return 0;
}

This is useful when different subsystems or components need separate logging streams.

---

Output format

Typical output uses the following conventions:

• function entry:

>> Foo()

• function exit:

<< Foo()

• with execution time:

<< Foo() [102ms]

• with return value:

<< Foo() 124 [102ms]

• arguments without names:

>> Foo() 123, abc

• arguments with names:

>> Foo() i=123, name=abc

---

Notes

• Use the LogmeP macro family for function tracing.
• Use LogmePV when no return value needs to be logged.
• Use LogmeP... without V when you want to log the return value through a result variable.
• Enable the Duration flag on the channel when execution time is needed.
• Use ARGS(...) for values and ARGS2(...) for names and values.