Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Trace block macro c #32

Merged
merged 2 commits into from
Jul 18, 2019
Merged
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Next Next commit
trace_utils: Implement GPUVIS_TRACE_BLOCK(F) for C
This commit ports the GPUVIS_TRACE_BLOCK / GPUVIS_TRACE_BLOCKF macros
that already existed for C++ to C (with GNU extensions). That allows
pure C programs on Linux to have a simple way of quickly tracing the
execution duration of a specific scope.

This is how it's implemented:

First, we generalize the C++ class to a struct. In C++, we add the
constructors/destructors to the struct, which makes it functionally the
same as before, but have the ctors/dtors call into _begin/_end
C functions. That way we can share the setup/finalize code between C and
C++ (even though it's very simple).

In C, the same struct is used. For construction, a GNU statement-expression
macro is used to initialize the struct in-line. For destruction, the
`cleanup` GNU attribute is used to execute a function that finalizes the
block.
  • Loading branch information
Heinrich committed Jul 16, 2019
commit 753135085309ca29a30014a5147af079c61db116
169 changes: 125 additions & 44 deletions sample/gpuvis_trace_utils.h
Original file line number Diff line number Diff line change
Expand Up @@ -38,17 +38,22 @@
#define GPUVIS_TRACE_UTILS_DISABLE
#endif

// printf-style warnings for user functions.
#if defined( __clang__ ) || defined( __GNUC__ )
// printf-style warnings for user functions.
#define GPUVIS_ATTR_PRINTF( _x, _y ) __attribute__( ( __format__( __printf__, _x, _y ) ) )
#define GPUVIS_MAY_BE_UNUSED __attribute__( ( unused ) )
#define GPUVIS_CLEANUP_FUNC( x ) __attribute__( ( __cleanup__( x ) ) )
#else
#define GPUVIS_ATTR_PRINTF( _x, _y )
#define GPUVIS_MAY_BE_UNUSED
#define GPUVIS_CLEANUP_FUNC( x )
#endif

#if !defined( GPUVIS_TRACE_UTILS_DISABLE )

#include <time.h>
#include <stdint.h>
#include <stdio.h>

#ifdef __cplusplus
#define GPUVIS_EXTERN extern "C"
Expand Down Expand Up @@ -106,78 +111,146 @@ GPUVIS_EXTERN const char *gpuvis_get_tracefs_filename( char *buf, size_t buflen,
// Internal function used by GPUVIS_COUNT_HOT_FUNC_CALLS macro
GPUVIS_EXTERN void gpuvis_count_hot_func_calls_internal_( const char *func );

static inline uint64_t gpuvis_gettime_u64( void )
{
struct timespec ts;
struct GpuvisTraceBlock;
static inline void gpuvis_trace_block_begin( struct GpuvisTraceBlock *block, const char *str );
static inline void gpuvis_trace_block_end( struct GpuvisTraceBlock *block );

clock_gettime( CLOCK_MONOTONIC, &ts );
return ( ( uint64_t )ts.tv_sec * 1000000000LL) + ts.tv_nsec;
}
struct GpuvisTraceBlockf;
static inline void gpuvis_trace_blockf_vbegin( struct GpuvisTraceBlockf *block, const char *fmt, va_list ap );
static inline void gpuvis_trace_blockf_begin( struct GpuvisTraceBlockf *block, const char *fmt, ... ) GPUVIS_ATTR_PRINTF( 2, 3 );
static inline void gpuvis_trace_blockf_end( struct GpuvisTraceBlockf *block );

#ifdef __cplusplus
#define LNAME3( _name, _line ) _name ## _line
#define LNAME2( _name, _line ) LNAME3( _name, _line )
#define LNAME( _name ) LNAME2( _name, __LINE__ )

class GpuvisTraceBlock
struct GpuvisTraceBlock
{
public:
GpuvisTraceBlock( const char *str ) : m_str( str )
uint64_t m_t0;
const char *m_str;

#ifdef __cplusplus
GpuvisTraceBlock( const char *str )
{
m_t0 = gpuvis_gettime_u64();
gpuvis_trace_block_begin( this, str );
}

~GpuvisTraceBlock()
{
uint64_t dt = gpuvis_gettime_u64() - m_t0;

// The cpu clock_gettime() functions seems to vary compared to the
// ftrace event timestamps. If we don't reduce the duration here,
// blocks oftentimes won't stack correctly when they're drawn.
if ( dt > 11000 )
dt -= 11000;
gpuvis_trace_printf( "%s (lduration=-%lu)", m_str, dt );
gpuvis_trace_block_end( this );
}

public:
uint64_t m_t0;
const char *m_str;
#endif
};

class GpuvisTraceBlockf
struct GpuvisTraceBlockf
{
public:
uint64_t m_t0;
char m_buf[ TRACE_BUF_SIZE ];

#ifdef __cplusplus
GpuvisTraceBlockf( const char *fmt, ... ) GPUVIS_ATTR_PRINTF( 2, 3 )
{
va_list args;

va_start( args, fmt );
vsnprintf( m_buf, sizeof( m_buf ), fmt, args );
gpuvis_trace_blockf_vbegin( this, fmt, args );
va_end( args );

m_t0 = gpuvis_gettime_u64();
}

~GpuvisTraceBlockf()
{
uint64_t dt = gpuvis_gettime_u64() - m_t0;

if ( dt > 11000 )
dt -= 11000;
gpuvis_trace_printf( "%s (lduration=-%lu)", m_buf, dt );
gpuvis_trace_blockf_end( this );
}

public:
uint64_t m_t0;
char m_buf[ TRACE_BUF_SIZE ];
#endif
};

#define LNAME3( _name, _line ) _name ## _line
#define LNAME2( _name, _line ) LNAME3( _name, _line )
#define LNAME( _name ) LNAME2( _name, __LINE__ )
#ifdef __cplusplus

#define GPUVIS_TRACE_BLOCK( _conststr ) GpuvisTraceBlock LNAME( gpuvistimeblock )( _conststr )
#define GPUVIS_TRACE_BLOCKF( _fmt, ... ) GpuvisTraceBlockf LNAME( gpuvistimeblock )( _fmt, __VA_ARGS__ )

#else

#if defined( __clang__ ) || defined( __GNUC__ )

#define GPUVIS_TRACE_BLOCKF_INIT( _unique, _fmt, ... ) \
({ \
struct GpuvisTraceBlockf _unique; \
gpuvis_trace_blockf_begin( & _unique, _fmt, __VA_ARGS__ ); \
_unique; \
})

#define GPUVIS_TRACE_BLOCKF( _fmt, ...) \
GPUVIS_CLEANUP_FUNC( gpuvis_trace_blockf_end ) GPUVIS_MAY_BE_UNUSED struct GpuvisTraceBlockf LNAME( gpuvistimeblock ) = \
GPUVIS_TRACE_BLOCKF_INIT( LNAME( gpuvistimeblock_init ), _fmt, __VA_ARGS__ )

#define GPUVIS_TRACE_BLOCK( _conststr ) \
GPUVIS_CLEANUP_FUNC( gpuvis_trace_block_end ) GPUVIS_MAY_BE_UNUSED struct GpuvisTraceBlock LNAME( gpuvistimeblock ) = \
{\
.m_t0 = gpuvis_gettime_u64(), \
.m_str = _conststr \
}

#else

#define GPUVIS_TRACE_BLOCKF( _fmt, ... )
#define GPUVIS_TRACE_BLOCK( _conststr )

#endif // __clang__ || __GNUC__

#endif // __cplusplus

static inline uint64_t gpuvis_gettime_u64( void )
{
struct timespec ts;

clock_gettime( CLOCK_MONOTONIC, &ts );
return ( ( uint64_t )ts.tv_sec * 1000000000LL) + ts.tv_nsec;
}

static inline void gpuvis_trace_block_finalize( uint64_t m_t0, const char *str )
{
uint64_t dt = gpuvis_gettime_u64() - m_t0;

// The cpu clock_gettime() functions seems to vary compared to the
// ftrace event timestamps. If we don't reduce the duration here,
// scopes oftentimes won't stack correctly when they're drawn.
if ( dt > 11000 )
dt -= 11000;

gpuvis_trace_printf( "%s (lduration=-%lu)", str, dt );
}

static inline void gpuvis_trace_block_begin( struct GpuvisTraceBlock* block, const char *str )
{
block->m_str = str;
block->m_t0 = gpuvis_gettime_u64();
}

static inline void gpuvis_trace_block_end( struct GpuvisTraceBlock *block )
{
gpuvis_trace_block_finalize(block->m_t0, block->m_str);
}

static inline void gpuvis_trace_blockf_vbegin( struct GpuvisTraceBlockf *block, const char *fmt, va_list ap)
{
vsnprintf(block->m_buf, sizeof(block->m_buf), fmt, ap);
block->m_t0 = gpuvis_gettime_u64();
}

static inline void gpuvis_trace_blockf_begin( struct GpuvisTraceBlockf *block, const char *fmt, ... )
{
va_list args;

va_start( args, fmt );
gpuvis_trace_blockf_vbegin( block, fmt, args );
va_end( args );
}

static inline void gpuvis_trace_blockf_end( struct GpuvisTraceBlockf *block )
{
gpuvis_trace_block_finalize( block->m_t0, block->m_buf );
}

#define GPUVIS_COUNT_HOT_FUNC_CALLS() gpuvis_count_hot_func_calls_internal_( __func__ );

#else
Expand Down Expand Up @@ -206,10 +279,18 @@ static inline int gpuvis_tracing_on() { return -1; }
static inline const char *gpuvis_get_tracefs_dir() { return ""; }
static inline const char *gpuvis_get_tracefs_filename( char *buf, size_t buflen, const char *file ) { return NULL; }

#ifdef __cplusplus
struct GpuvisTraceBlock {};

static inline void gpuvis_trace_block_begin( struct GpuvisTraceBlock *block, const char *str ) {}
static inline void gpuvis_trace_block_end( struct GpuvisTraceBlock *block ) {}

struct GpuvisTraceBlockf {};
static inline void gpuvis_trace_blockf_vbegin( struct GpuvisTraceBlockf *block, const char *fmt, va_list ap ) {}
static inline void gpuvis_trace_blockf_begin( struct GpuvisTraceBlockf *block, const char *fmt, ... ) {}
static inline void gpuvis_trace_blockf_end( struct GpuvisTraceBlockf *block ) {}

#define GPUVIS_TRACE_BLOCK( _conststr )
#define GPUVIS_TRACE_BLOCKF( _fmt, ... )
#endif

#define GPUVIS_COUNT_HOT_FUNC_CALLS()

Expand Down