Scoped Events

Macros
#define	TRACE_EVENT(category, name, ...)
#define	TRACE_EVENT0(category, name)
#define	TRACE_EVENT1(category, name, arg1_name, arg1)
#define	TRACE_EVENT2(category, name, arg1_name, arg1, arg2_name, arg2)
#define	TRACE_FUNCTION(category, ...)   TRACE_EVENT(category, __func__, __VA_ARGS__)
#define	TRACE_FUNCTION0(category)   TRACE_EVENT0(category, __func__)
#define	TRACE_FUNCTION1(category, arg1_name, arg1)   TRACE_EVENT1(category, __func__, arg1_name, arg1)
#define	TRACE_FUNCTION2(category, arg1_name, arg1, arg2_name, arg2)   TRACE_EVENT2(category, __func__, arg1_name, arg1, arg2_name, arg2)
#define	TRACE_LOCKGUARD(mutex, category, name)

Detailed Description

Scoped events are used for events that should log synchronously both a start and an end event automatically according to a scope.

The TRACE_FUNCTION event macros are identical to the TRACE_EVENT macros except they don't accept a name parameter and the name is predefined as the function name (using __func__).

Example:

void defragment_part(int vbucket) {
    // Set up a scoped event and log the start event
    TRACE_EVENT("ep-engine:vbucket", "defragment_part", vbucket);

    // Perform the de-fragmentation and take some time doing it
    ...

} // Automatically log a synchronous end event on function exit
  // (Through return or exception)

The TRACE_LOCKGUARD macro measures for a given mutex both the duration for acquiring the lock and the duration the lock is held. This is achieved by issuing two pairs of TRACE_EVENT_START0 / TRACE_EVENT_END0 events.

Example:

TRACE_LOCKGUARD(mutex, "category", "lock_name");

This example will produce the following 4 events:

1) START_EVENT "cat" = "category" "name" = "lock_name.acquire" 2) END_EVENT "cat" = "category" "name" = "lock_name.acquire" 3) START_EVENT "cat" = "category" "name" = "lock_name.held" 4) END_EVENT "cat" = "category" "name" = "lock_name.held"

Macro Definition Documentation

#define TRACE_EVENT	(		category,
			name,
			...
	)

Value:

static constexpr const char* PHOSPHOR_INTERNAL_UID(nme) = name;   \
    TRACE_EVENT_START(category, name, __VA_ARGS__);                   \
    struct PHOSPHOR_INTERNAL_UID(scoped_trace_t) {                    \
        ~PHOSPHOR_INTERNAL_UID(scoped_trace_t)() {                    \
            TRACE_EVENT_END0(category, PHOSPHOR_INTERNAL_UID(nme));   \
        }                                                             \
    } PHOSPHOR_INTERNAL_UID(scoped_trace_inst);

#define TRACE_EVENT0	(		category,
			name
	)

Value:

static constexpr const char* PHOSPHOR_INTERNAL_UID(nme) = name;   \
    TRACE_EVENT_START0(category, name);                               \
    struct PHOSPHOR_INTERNAL_UID(scoped_trace_t) {                    \
        ~PHOSPHOR_INTERNAL_UID(scoped_trace_t)() {                    \
            TRACE_EVENT_END0(category, PHOSPHOR_INTERNAL_UID(nme));\
        }                                                             \
    } PHOSPHOR_INTERNAL_UID(scoped_trace_inst);

#define TRACE_EVENT1	(		category,
			name,
			arg1_name,
			arg1
	)

Value:

static constexpr const char* PHOSPHOR_INTERNAL_UID(nme) = name;   \
    TRACE_EVENT_START1(category, name, arg1_name, arg1);              \
    struct PHOSPHOR_INTERNAL_UID(scoped_trace_t) {                    \
        ~PHOSPHOR_INTERNAL_UID(scoped_trace_t)() {                    \
            TRACE_EVENT_END0(category, PHOSPHOR_INTERNAL_UID(nme));   \
        }                                                             \
    } PHOSPHOR_INTERNAL_UID(scoped_trace_inst);

#define TRACE_EVENT2	(		category,
			name,
			arg1_name,
			arg1,
			arg2_name,
			arg2
	)

Value:

static constexpr const char* PHOSPHOR_INTERNAL_UID(nme) = name;   \
    TRACE_EVENT_START2(category, name, arg1_name, arg1, arg2_name, arg2); \
    struct PHOSPHOR_INTERNAL_UID(scoped_trace_t) {                    \
        ~PHOSPHOR_INTERNAL_UID(scoped_trace_t)() {                    \
            TRACE_EVENT_END0(category, PHOSPHOR_INTERNAL_UID(nme));   \
        }                                                             \
    } PHOSPHOR_INTERNAL_UID(scoped_trace_inst);

#define TRACE_LOCKGUARD	(		mutex,
			category,
			name
	)

Value:

static constexpr const char* PHOSPHOR_INTERNAL_UID(nme) = name ".held";  \
    static decltype(mutex)& PHOSPHOR_INTERNAL_UID(lk)(mutex);            \
    TRACE_EVENT_START0(category, name ".acquire");                       \
    PHOSPHOR_INTERNAL_UID(lk).lock();                                    \
    PHOSPHOR_INTERNAL_ADDITIONAL_TRACE_EVENT0(                               \
        second_tpi, category, name ".acquire", phosphor::TraceEvent::Type::SyncEnd); \
    PHOSPHOR_INTERNAL_ADDITIONAL_TRACE_EVENT0(                                \
        third_tpi, category, name ".held", phosphor::TraceEvent::Type::SyncStart);  \
    struct PHOSPHOR_INTERNAL_UID(scoped_trace_t) {                       \
        ~PHOSPHOR_INTERNAL_UID(scoped_trace_t)() {                       \
            PHOSPHOR_INTERNAL_UID(lk).unlock();                          \
            TRACE_EVENT_END0(category, PHOSPHOR_INTERNAL_UID(nme));      \
        }                                                                \
    } PHOSPHOR_INTERNAL_UID(scoped_trace_inst);