From d6451f79a61c34650e2635eec2ea959043c53a1a Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Wed, 15 Jul 2026 06:49:26 -0500 Subject: [PATCH 01/10] switch reference collector to generate json perfetto trace --- src/ittnotify_refcol/README.md | 36 +- src/ittnotify_refcol/itt_refcol_impl.c | 472 +++++++++++-------- src/ittnotify_refcol/tests/run_smoke_test.py | 34 +- 3 files changed, 312 insertions(+), 230 deletions(-) diff --git a/src/ittnotify_refcol/README.md b/src/ittnotify_refcol/README.md index 30efd67e..909b40eb 100644 --- a/src/ittnotify_refcol/README.md +++ b/src/ittnotify_refcol/README.md @@ -1,7 +1,10 @@ # Instrumentation and Tracing Technology (ITT) API Reference Collector This is a reference implementation of the ITT API *dynamic* part that -performs tracing data from ITT API function calls to log files. +translates ITT API function calls into a +[Perfetto / Chrome Trace Event](https://ui.perfetto.dev) trace written in JSON. +The resulting file can be opened directly in or +`chrome://tracing`. To use this solution, build the collector as a shared library and point the full library path to the `INTEL_LIBITTNOTIFY64` environment variable. @@ -54,7 +57,7 @@ setenv INTEL_LIBITTNOTIFY64 /libittnotify_refcol.so set INTEL_LIBITTNOTIFY64=\libittnotify_refcol.dll ``` -By default, log files are saved in the system temporary directory. To change +By default, trace files are saved in the system temporary directory. To change the location, use the `INTEL_LIBITTNOTIFY_LOG_DIR` environment variable: **On Linux** @@ -73,13 +76,22 @@ setenv INTEL_LIBITTNOTIFY_LOG_DIR set INTEL_LIBITTNOTIFY_LOG_DIR= ``` -This implementation adds logging of some of the ITT API function calls. Adding -logging of other ITT API function calls is welcome. The solution provides 4 -functions with different log levels that take `printf` format for logging: - -```c -LOG_FUNC_CALL_INFO(const char *msg_format, ...); -LOG_FUNC_CALL_WARN(const char *msg_format, ...); -LOG_FUNC_CALL_ERROR(const char *msg_format, ...); -LOG_FUNC_CALL_FATAL(const char *msg_format, ...); -``` +The collector writes one trace file per run named +`libittnotify_refcol_.json`. It is a Chrome Trace Event trace in the +streaming-friendly "JSON Array Format", so it loads directly into + or `chrome://tracing`. ITT API calls are mapped to +trace events as follows: + +| ITT API | Trace event phase | +|-----------------------------|--------------------------------------------| +| `__itt_task_begin` / `_end` | `B` / `E` (synchronous, per-thread) | +| `__itt_region_begin`/`_end` | `b` / `e` (asynchronous, matched by id) | +| `__itt_frame_begin`/`_end` | `b` / `e` (asynchronous, matched by id) | +| `__itt_frame_submit_v3` | `X` (complete event with explicit duration)| +| `__itt_counter_set_value` | `C` (counter series) | +| metadata / pause / resume | `i` (thread-scoped instant marker) | + +Each event carries an `itt_api` argument identifying the originating ITT call. +Adding support for other ITT API calls is welcome: emit events with the +`trace_emit()` helper, which takes a phase, category, name, timestamp, and an +optional raw-JSON `extra` field (for `args`, `id`, `dur`, etc.). diff --git a/src/ittnotify_refcol/itt_refcol_impl.c b/src/ittnotify_refcol/itt_refcol_impl.c index 3e1acec3..2387b7f2 100644 --- a/src/ittnotify_refcol/itt_refcol_impl.c +++ b/src/ittnotify_refcol/itt_refcol_impl.c @@ -10,6 +10,9 @@ #include #include #include +#ifndef _WIN32 +#include +#endif #define INTEL_NO_MACRO_BODY #define INTEL_ITTNOTIFY_API_PRIVATE @@ -19,19 +22,16 @@ #define LOG_BUFFER_MAX_SIZE 256 static const char* env_log_dir = "INTEL_LIBITTNOTIFY_LOG_DIR"; -static const char* log_level_str[] = {"INFO", "WARN", "ERROR", "FATAL_ERROR"}; - -enum { - LOG_LVL_INFO, - LOG_LVL_WARN, - LOG_LVL_ERROR, - LOG_LVL_FATAL -}; +// The collector emits a Perfetto / Chrome Trace Event trace in the streaming +// friendly "JSON Array Format": the file is a single JSON array of event +// objects. It can be opened directly in https://ui.perfetto.dev or +// chrome://tracing. static struct ref_collector_logger { - FILE* log_fp; + FILE* log_fp; uint8_t init_state; -} g_ref_collector_logger = {NULL, 0}; + uint8_t first_event; // false once the first event has been written (controls comma separators) +} g_ref_collector_logger = {NULL, 0, 1}; // Collector maintains its own object lists instead of relying on __itt_global*, // because traced apps may contain multiple static ITT parts, each with its own __itt_global*. @@ -71,7 +71,7 @@ static char* log_file_name_generate() return NULL; } - snprintf(log_file_name, LOG_BUFFER_MAX_SIZE/2, "libittnotify_refcol_%d%d%d%d%d%d.log", + snprintf(log_file_name, LOG_BUFFER_MAX_SIZE/2, "libittnotify_refcol_%d%d%d%d%d%d.json", time_info.tm_year+1900, time_info.tm_mon+1, time_info.tm_mday, time_info.tm_hour, time_info.tm_min, time_info.tm_sec); @@ -115,13 +115,16 @@ static void ref_collector_init() } free(log_file); - g_ref_collector_logger.log_fp = fopen(file_name_buffer, "a"); + g_ref_collector_logger.log_fp = fopen(file_name_buffer, "w"); if (!g_ref_collector_logger.log_fp) { - printf("ERROR: Cannot open log file: %s\n", file_name_buffer); + printf("ERROR: Cannot open trace file: %s\n", file_name_buffer); return; } + // Open the Chrome Trace Event JSON array. + fprintf(g_ref_collector_logger.log_fp, "[\n"); + g_ref_collector_logger.first_event = 1; g_ref_collector_logger.init_state = 1; } } @@ -154,6 +157,8 @@ static void ref_collector_release(void) if (g_ref_collector_logger.log_fp) { + // Close the Chrome Trace Event JSON array. + fprintf(g_ref_collector_logger.log_fp, "\n]\n"); fclose(g_ref_collector_logger.log_fp); g_ref_collector_logger.log_fp = NULL; } @@ -273,32 +278,111 @@ ITT_EXTERN_C void ITTAPI __itt_api_init(__itt_global* p, __itt_group_id init_gro } } -static void log_func_call(uint8_t log_level, const char* function_name, const char* message_format, ...) +// ---------------------------------------------------------------------------- +// Perfetto / Chrome Trace Event writer +// +// Every instrumented ITT API call is translated into one or more trace events +// and appended to the JSON array opened in ref_collector_init(). The resulting +// file loads directly in https://ui.perfetto.dev or chrome://tracing. +// +// Event phase mapping: +// task begin / end -> "B" / "E" (synchronous, per-thread, nestable) +// region begin / end -> "b" / "e" (asynchronous, matched by id) +// frame begin / end -> "b" / "e" (asynchronous, matched by id) +// frame submit -> "X" (complete event with explicit duration) +// counter set value -> "C" (counter series) +// everything else -> "i" (thread-scoped instant marker) +// ---------------------------------------------------------------------------- + +#ifdef _WIN32 +static uint64_t get_timestamp_us(void) { - if (!g_ref_collector_logger.init_state || !g_ref_collector_logger.log_fp) + LARGE_INTEGER freq, cnt; + QueryPerformanceFrequency(&freq); + QueryPerformanceCounter(&cnt); + if (freq.QuadPart == 0) return 0; + return (uint64_t)((cnt.QuadPart * 1000000ULL) / (uint64_t)freq.QuadPart); +} +static int get_process_id(void) { return (int)GetCurrentProcessId(); } +#else +static uint64_t get_timestamp_us(void) +{ + struct timespec ts; + clock_gettime(CLOCK_MONOTONIC, &ts); + return (uint64_t)ts.tv_sec * 1000000ULL + (uint64_t)ts.tv_nsec / 1000ULL; +} +static int get_process_id(void) { return (int)getpid(); } +#endif + +static unsigned long long get_thread_id(void) +{ + return (unsigned long long)(uintptr_t)__itt_thread_id(); +} + +// Escape a string so it can be safely embedded inside a JSON string literal. +static void json_escape(const char* src, char* dst, size_t dst_size) +{ + size_t j = 0; + if (dst_size == 0) return; + if (src == NULL) { dst[0] = '\0'; return; } + + for (size_t i = 0; src[i] != '\0' && j + 1 < dst_size; i++) { - printf("ERROR: Failed to log function call\n"); - return; + unsigned char c = (unsigned char)src[i]; + switch (c) + { + case '\"': if (j + 2 < dst_size) { dst[j++] = '\\'; dst[j++] = '\"'; } break; + case '\\': if (j + 2 < dst_size) { dst[j++] = '\\'; dst[j++] = '\\'; } break; + case '\n': if (j + 2 < dst_size) { dst[j++] = '\\'; dst[j++] = 'n'; } break; + case '\r': if (j + 2 < dst_size) { dst[j++] = '\\'; dst[j++] = 'r'; } break; + case '\t': if (j + 2 < dst_size) { dst[j++] = '\\'; dst[j++] = 't'; } break; + default: + if (c < 0x20) + { + if (j + 6 < dst_size) + j += (size_t)snprintf(dst + j, dst_size - j, "\\u%04x", c); + } + else + { + dst[j++] = (char)c; + } + break; + } } + dst[j] = '\0'; +} - char log_buffer[LOG_BUFFER_MAX_SIZE]; - uint32_t result_len = 0; - va_list message_args; +// Append a single trace event object to the JSON array. Thread-safe. +// `extra` (may be NULL) is raw JSON appended after the mandatory fields, e.g. +// ",\"dur\":123", ",\"id\":\"0x1\"", ",\"s\":\"t\"", ",\"args\":{...}". +static void trace_emit(const char* phase, const char* cat, const char* name, + uint64_t ts, const char* extra) +{ + if (!g_ref_collector_logger.init_state || !g_ref_collector_logger.log_fp) + return; + if (!g_ref_collector_global.mutex_initialized) + return; - result_len += snprintf(log_buffer, LOG_BUFFER_MAX_SIZE, "[%s] %s(...) - ", log_level_str[log_level], function_name); - if (result_len >= LOG_BUFFER_MAX_SIZE) - result_len = LOG_BUFFER_MAX_SIZE - 1; - va_start(message_args, message_format); - vsnprintf(log_buffer + result_len, LOG_BUFFER_MAX_SIZE - result_len, message_format, message_args); - va_end(message_args); + char name_esc[LOG_BUFFER_MAX_SIZE]; + char cat_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(name, name_esc, sizeof(name_esc)); + json_escape(cat, cat_esc, sizeof(cat_esc)); - fprintf(g_ref_collector_logger.log_fp, "%s\n", log_buffer); -} + __itt_mutex_lock(&g_ref_collector_global.mutex); + + fprintf(g_ref_collector_logger.log_fp, + "%s{\"name\":\"%s\",\"cat\":\"%s\",\"ph\":\"%s\",\"ts\":%" PRIu64 + ",\"pid\":%d,\"tid\":%llu", + g_ref_collector_logger.first_event ? "" : ",\n", + name_esc, cat_esc, phase, ts, get_process_id(), get_thread_id()); + if (extra != NULL) + fputs(extra, g_ref_collector_logger.log_fp); + fputc('}', g_ref_collector_logger.log_fp); + + g_ref_collector_logger.first_event = 0; -#define LOG_FUNC_CALL_INFO(...) log_func_call(LOG_LVL_INFO, __FUNCTION__, __VA_ARGS__) -#define LOG_FUNC_CALL_WARN(...) log_func_call(LOG_LVL_WARN, __FUNCTION__, __VA_ARGS__) -#define LOG_FUNC_CALL_ERROR(...) log_func_call(LOG_LVL_ERROR, __FUNCTION__, __VA_ARGS__) -#define LOG_FUNC_CALL_FATAL(...) log_func_call(LOG_LVL_FATAL, __FUNCTION__, __VA_ARGS__) + __itt_mutex_unlock(&g_ref_collector_global.mutex); +} // ---------------------------------------------------------------------------- // The code below is a reference implementation of the ITT API functions. @@ -435,7 +519,6 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) { if (!g_ref_collector_global.mutex_initialized || name == NULL) { - LOG_FUNC_CALL_WARN("Cannot create domain object"); return NULL; } @@ -451,11 +534,6 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) if (h == NULL) { NEW_DOMAIN_A(&g_ref_collector_global, h, h_tail, name); - LOG_FUNC_CALL_INFO("function args: name=%s (created new domain)", name); - } - else - { - LOG_FUNC_CALL_INFO("function args: name=%s (domain already exists)", name); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -478,7 +556,6 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* { if (!g_ref_collector_global.mutex_initialized || name == NULL) { - LOG_FUNC_CALL_WARN("Cannot create string handle object"); return NULL; } @@ -494,11 +571,6 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* if (h == NULL) { NEW_STRING_HANDLE_A(&g_ref_collector_global, h, h_tail, name); - LOG_FUNC_CALL_INFO("function args: name=%s (created new string handle)", name); - } - else - { - LOG_FUNC_CALL_INFO("function args: name=%s (string handle already exists)", name); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -521,7 +593,6 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_createA(const char *name, const ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create(const char *name, const char *domain) #endif { - LOG_FUNC_CALL_INFO("function call"); return __itt_counter_create_typed(name, domain, __itt_metadata_u64); } @@ -545,10 +616,8 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_v3( { if (domain == NULL) { - LOG_FUNC_CALL_WARN("domain is NULL"); return NULL; } - LOG_FUNC_CALL_INFO("function call"); return __itt_counter_create_typed(name, domain->nameA, type); } @@ -572,7 +641,6 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( { if (!g_ref_collector_global.mutex_initialized || name == NULL || domain == NULL) { - LOG_FUNC_CALL_WARN("Cannot create counter object"); return NULL; } @@ -590,13 +658,6 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( if (h == NULL) { NEW_COUNTER_A(&g_ref_collector_global, h, h_tail, name, domain, type); - LOG_FUNC_CALL_INFO("function args: name=%s, domain=%s, type=%d (created new counter)", - name, domain, (int)type); - } - else - { - LOG_FUNC_CALL_INFO("function args: name=%s, domain=%s, type=%d (counter already exists)", - name, domain, (int)type); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -622,7 +683,6 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( { if (!g_ref_collector_global.mutex_initialized || name == NULL || domain == NULL) { - LOG_FUNC_CALL_WARN("Cannot create histogram object"); return NULL; } @@ -638,13 +698,6 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( if (h == NULL) { NEW_HISTOGRAM_A(&g_ref_collector_global, h, h_tail, domain, name, x_type, y_type); - LOG_FUNC_CALL_INFO("function args: domain=%s, name=%s, x_type=%d, y_type=%d (created new histogram)", - domain->nameA, name, x_type, y_type); - } - else - { - LOG_FUNC_CALL_INFO("function args: domain=%s, name=%s, x_type=%d, y_type=%d (histogram already exists)", - domain->nameA, name, x_type, y_type); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -654,234 +707,235 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( ITT_EXTERN_C void ITTAPI __itt_pause(void) { - LOG_FUNC_CALL_INFO("function call"); + trace_emit("i", "itt", "__itt_pause", get_timestamp_us(), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_pause\"}"); } ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) { - LOG_FUNC_CALL_INFO("function args: scope=%d", scope); + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_pause_scoped\",\"scope\":%d}", (int)scope); + trace_emit("i", "itt", "__itt_pause_scoped", get_timestamp_us(), extra); } ITT_EXTERN_C void ITTAPI __itt_resume(void) { - LOG_FUNC_CALL_INFO("function call"); + trace_emit("i", "itt", "__itt_resume", get_timestamp_us(), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_resume\"}"); } ITT_EXTERN_C void ITTAPI __itt_resume_scoped(__itt_collection_scope scope) { - LOG_FUNC_CALL_INFO("function args: scope=%d", scope); + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_resume_scoped\",\"scope\":%d}", (int)scope); + trace_emit("i", "itt", "__itt_resume_scoped", get_timestamp_us(), extra); } ITT_EXTERN_C void ITTAPI __itt_detach(void) { - LOG_FUNC_CALL_INFO("function call"); + trace_emit("i", "itt", "__itt_detach", get_timestamp_us(), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_detach\"}"); } ITT_EXTERN_C void ITTAPI __itt_frame_begin_v3(const __itt_domain *domain, __itt_id *id) { - if (domain != NULL) - { - (void)id; - LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL) return; + + unsigned long long fid = (id != NULL) ? id->d1 : 0; + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_frame_begin_v3\"}", fid); + trace_emit("b", domain->nameA, domain->nameA, get_timestamp_us(), extra); } ITT_EXTERN_C void ITTAPI __itt_frame_end_v3(const __itt_domain *domain, __itt_id *id) { - if (domain != NULL) - { - (void)id; - LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL) return; + + unsigned long long fid = (id != NULL) ? id->d1 : 0; + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_frame_end_v3\"}", fid); + trace_emit("e", domain->nameA, domain->nameA, get_timestamp_us(), extra); } ITT_EXTERN_C void ITTAPI __itt_frame_submit_v3(const __itt_domain *domain, __itt_id *id, __itt_timestamp begin, __itt_timestamp end) { - if (domain != NULL) - { - (void)id; - LOG_FUNC_CALL_INFO("function args: domain=%s, time_begin=%llu, time_end=%llu", - domain->nameA, begin, end); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL) return; + + (void)id; + uint64_t dur = (end > begin) ? (uint64_t)(end - begin) : 0; + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"dur\":%" PRIu64 ",\"args\":{\"itt_api\":\"__itt_frame_submit_v3\"," + "\"time_begin\":%llu,\"time_end\":%llu}", + dur, (unsigned long long)begin, (unsigned long long)end); + trace_emit("X", domain->nameA, domain->nameA, (uint64_t)begin, extra); } ITT_EXTERN_C void ITTAPI __itt_task_begin( const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) { - if (domain != NULL && name != NULL) - { - LOG_FUNC_CALL_INFO("function args: domain=%s name=%s taskid=%llu,%llu,%llu parentid=%llu,%llu,%llu", - domain->nameA, name->strA, - taskid.d1, taskid.d2, taskid.d3, - parentid.d1, parentid.d2, parentid.d3); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL || name == NULL) return; + + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"args\":{\"itt_api\":\"__itt_task_begin\"," + "\"taskid\":\"%llu,%llu,%llu\",\"parentid\":\"%llu,%llu,%llu\"}", + taskid.d1, taskid.d2, taskid.d3, + parentid.d1, parentid.d2, parentid.d3); + trace_emit("B", domain->nameA, name->strA, get_timestamp_us(), extra); } ITT_EXTERN_C void ITTAPI __itt_task_end(const __itt_domain *domain) { - if (domain != NULL) - { - LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL) return; + + trace_emit("E", domain->nameA, "", get_timestamp_us(), + ",\"args\":{\"itt_api\":\"__itt_task_end\"}"); } ITT_EXTERN_C void ITTAPI __itt_region_begin( const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) { - if (domain != NULL && name != NULL) - { - LOG_FUNC_CALL_INFO("function args: domain=%s name=%s id=%llu,%llu,%llu parentid=%llu,%llu,%llu", - domain->nameA, name->strA, - id.d1, id.d2, id.d3, - parentid.d1, parentid.d2, parentid.d3); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL || name == NULL) return; + + (void)parentid; + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_region_begin\"}", id.d1); + trace_emit("b", domain->nameA, name->strA, get_timestamp_us(), extra); } ITT_EXTERN_C void ITTAPI __itt_region_end(const __itt_domain *domain, __itt_id id) { - if (domain != NULL) - { - LOG_FUNC_CALL_INFO("function args: domain=%s id=%llu,%llu,%llu", - domain->nameA, id.d1, id.d2, id.d3); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL) return; + + char extra[LOG_BUFFER_MAX_SIZE]; + snprintf(extra, sizeof(extra), + ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_region_end\"}", id.d1); + trace_emit("e", domain->nameA, "", get_timestamp_us(), extra); } ITT_EXTERN_C void __itt_metadata_add(const __itt_domain *domain, __itt_id id, __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) { - if (domain != NULL && count != 0) - { - (void)id; - (void)key; - char* metadata_str = get_metadata_elements(count, type, data); - LOG_FUNC_CALL_INFO("function args: domain=%s metadata_size=%zu metadata[]=%s", - domain->nameA, count, metadata_str); - free(metadata_str); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (domain == NULL || count == 0) return; + + (void)id; + char* metadata_str = get_metadata_elements(count, type, data); + char key_esc[LOG_BUFFER_MAX_SIZE]; + char data_esc[LOG_BUFFER_MAX_SIZE]; + json_escape((key != NULL) ? key->strA : "", key_esc, sizeof(key_esc)); + json_escape(metadata_str, data_esc, sizeof(data_esc)); + + char extra[LOG_BUFFER_MAX_SIZE * 2]; + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_metadata_add\"," + "\"key\":\"%s\",\"count\":%zu,\"data\":\"%s\"}", + key_esc, count, data_esc); + trace_emit("i", domain->nameA, (key != NULL) ? key->strA : "metadata", + get_timestamp_us(), extra); + free(metadata_str); } ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt_string_handle *format, ...) { - if (domain == NULL || format == NULL) - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } + if (domain == NULL || format == NULL) return; va_list args; va_start(args, format); - char formatted_metadata[LOG_BUFFER_MAX_SIZE]; vsnprintf(formatted_metadata, LOG_BUFFER_MAX_SIZE, format->strA, args); + va_end(args); - LOG_FUNC_CALL_INFO("function args: domain=%s formatted_metadata=%s", - domain->nameA, formatted_metadata); + char data_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(formatted_metadata, data_esc, sizeof(data_esc)); - va_end(args); + char extra[LOG_BUFFER_MAX_SIZE * 2]; + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_formatted_metadata_add\",\"data\":\"%s\"}", + data_esc); + trace_emit("i", domain->nameA, "__itt_formatted_metadata_add", get_timestamp_us(), extra); } ITT_EXTERN_C void __itt_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) { - if (hist == NULL) - { - LOG_FUNC_CALL_WARN("Histogram is NULL"); - } - else if (hist->domain == NULL) + if (hist == NULL || hist->domain == NULL || hist->domain->nameA == NULL || + hist->nameA == NULL || length == 0 || y_data == NULL) { - LOG_FUNC_CALL_WARN("Histogram domain is NULL"); + return; } - else if (hist->domain->nameA != NULL && hist->nameA != NULL && length != 0 && y_data != NULL) + + char* y_str = get_metadata_elements(length, hist->y_type, y_data); + char y_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(y_str, y_esc, sizeof(y_esc)); + free(y_str); + + char extra[LOG_BUFFER_MAX_SIZE * 3]; + if (x_data != NULL) { - if (x_data != NULL) - { - char* x_data_str = get_metadata_elements(length, hist->x_type, x_data); - char* y_data_str = get_metadata_elements(length, hist->y_type, y_data); - LOG_FUNC_CALL_INFO("function args: domain=%s name=%s histogram_size=%zu x[]=%s y[]=%s", - hist->domain->nameA, hist->nameA, length, x_data_str, y_data_str); - free(x_data_str); - free(y_data_str); - } - else - { - char* y_data_str = get_metadata_elements(length, hist->y_type, y_data); - LOG_FUNC_CALL_INFO("function args: domain=%s name=%s histogram_size=%zu y[]=%s", - hist->domain->nameA, hist->nameA, length, y_data_str); - free(y_data_str); - } + char* x_str = get_metadata_elements(length, hist->x_type, x_data); + char x_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(x_str, x_esc, sizeof(x_esc)); + free(x_str); + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_histogram_submit\"," + "\"length\":%zu,\"x\":\"%s\",\"y\":\"%s\"}", + length, x_esc, y_esc); } else { - LOG_FUNC_CALL_WARN("Incorrect function call"); + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_histogram_submit\"," + "\"length\":%zu,\"y\":\"%s\"}", + length, y_esc); } + trace_emit("i", hist->domain->nameA, hist->nameA, get_timestamp_us(), extra); } ITT_EXTERN_C void __itt_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) { - if (counter != NULL && metadata != NULL && length != 0) - { - __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; - char context_metadata[LOG_BUFFER_MAX_SIZE]; - context_metadata[0] = '\0'; - uint16_t offset = 0; - for(size_t i=0; inameA, length, context_metadata); - } - else + if (counter == NULL || metadata == NULL || length == 0) return; + + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + char context_metadata[LOG_BUFFER_MAX_SIZE]; + context_metadata[0] = '\0'; + uint16_t offset = 0; + for (size_t i = 0; i < length && offset < LOG_BUFFER_MAX_SIZE - 1; i++) { - LOG_FUNC_CALL_WARN("Incorrect function call"); + char* elem = get_context_metadata_element(metadata[i].type, metadata[i].value); + offset += (uint16_t)snprintf(context_metadata + offset, LOG_BUFFER_MAX_SIZE - offset, "%s", elem); + free(elem); } + + char ctx_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(context_metadata, ctx_esc, sizeof(ctx_esc)); + + char extra[LOG_BUFFER_MAX_SIZE * 2]; + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_bind_context_metadata_to_counter\"," + "\"length\":%zu,\"context\":\"%s\"}", + length, ctx_esc); + trace_emit("i", "counter", (counter_info->nameA != NULL) ? counter_info->nameA : "", + get_timestamp_us(), extra); } ITT_EXTERN_C void __itt_counter_set_value_v3(__itt_counter counter, void* value_ptr) { - if (counter != NULL && value_ptr != NULL) - { - __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; - uint64_t value = *(uint64_t*)value_ptr; - LOG_FUNC_CALL_INFO("function args: counter_name=%s counter_value=%" PRIu64, - counter_info->nameA, value); - } - else - { - LOG_FUNC_CALL_WARN("Incorrect function call"); - } + if (counter == NULL || value_ptr == NULL) return; + + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + uint64_t value = *(uint64_t*)value_ptr; + const char* series = (counter_info->nameA != NULL) ? counter_info->nameA : "value"; + + char series_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(series, series_esc, sizeof(series_esc)); + + char extra[LOG_BUFFER_MAX_SIZE * 2]; + snprintf(extra, sizeof(extra), ",\"args\":{\"%s\":%" PRIu64 "}", series_esc, value); + trace_emit("C", "counter", series, get_timestamp_us(), extra); } diff --git a/src/ittnotify_refcol/tests/run_smoke_test.py b/src/ittnotify_refcol/tests/run_smoke_test.py index cea0c657..ba245411 100644 --- a/src/ittnotify_refcol/tests/run_smoke_test.py +++ b/src/ittnotify_refcol/tests/run_smoke_test.py @@ -6,13 +6,14 @@ import argparse import glob +import json import os import subprocess import sys import tempfile -EXPECTED_SYMBOLS = [ +EXPECTED_ITT_APIS = [ "__itt_task_begin", "__itt_task_end", "__itt_metadata_add", @@ -52,21 +53,36 @@ def main(): print(f"ERROR: smoke test executable exited with code {result.returncode}") return 1 - logs = glob.glob(os.path.join(log_dir, "libittnotify_refcol_*.log")) + logs = glob.glob(os.path.join(log_dir, "libittnotify_refcol_*.json")) if not logs: - print("ERROR: no log file found in", log_dir) + print("ERROR: no trace file found in", log_dir) return 1 - log_path = logs[0] - print(f"Log file: {log_path}") + trace_path = logs[0] + print(f"Trace file: {trace_path}") - with open(log_path, encoding="utf-8", errors="replace") as f: + with open(trace_path, encoding="utf-8", errors="replace") as f: content = f.read() - missing = [sym for sym in EXPECTED_SYMBOLS if sym not in content] + try: + events = json.loads(content) + except json.JSONDecodeError as exc: + print(f"ERROR: trace file is not valid JSON: {exc}") + return 1 + + if not isinstance(events, list) or not events: + print("ERROR: trace file does not contain a non-empty JSON array of events") + return 1 + + seen_apis = { + e.get("args", {}).get("itt_api") + for e in events + if isinstance(e, dict) and isinstance(e.get("args"), dict) + } + missing = [api for api in EXPECTED_ITT_APIS if api not in seen_apis] if missing: - for sym in missing: - print(f"ERROR: '{sym}' not found in log") + for api in missing: + print(f"ERROR: '{api}' event not found in trace") return 1 print("Smoke test passed.") From 80eaa0242193088abf6eea44c4745a27c957fe58 Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Wed, 15 Jul 2026 10:11:48 -0500 Subject: [PATCH 02/10] add 2 modes --- src/ittnotify_refcol/README.md | 65 +++- src/ittnotify_refcol/itt_refcol_impl.c | 472 +++++++++++++++++++++---- 2 files changed, 465 insertions(+), 72 deletions(-) diff --git a/src/ittnotify_refcol/README.md b/src/ittnotify_refcol/README.md index 909b40eb..c46f380a 100644 --- a/src/ittnotify_refcol/README.md +++ b/src/ittnotify_refcol/README.md @@ -1,10 +1,19 @@ # Instrumentation and Tracing Technology (ITT) API Reference Collector -This is a reference implementation of the ITT API *dynamic* part that -translates ITT API function calls into a -[Perfetto / Chrome Trace Event](https://ui.perfetto.dev) trace written in JSON. -The resulting file can be opened directly in or -`chrome://tracing`. +This is a reference implementation of the ITT API *dynamic* part. It records the +ITT API function calls made by an instrumented application and can produce the +output in one of two modes: + +1. **Text log (default)** — a human-readable `.log` file with one line per ITT + API call, describing the call and its arguments. +2. **JSON trace** — a + [Perfetto / Chrome Trace Event](https://ui.perfetto.dev) trace written in + JSON, which can be opened directly in or + `chrome://tracing`. + +The mode is selected with the `EXP_LIBITTNOTIFY_GEN_JSON` environment variable +(see [Output modes](#output-modes) below). By default the collector produces the +plain-text log. To use this solution, build the collector as a shared library and point the full library path to the `INTEL_LIBITTNOTIFY64` environment variable. @@ -76,9 +85,44 @@ setenv INTEL_LIBITTNOTIFY_LOG_DIR set INTEL_LIBITTNOTIFY_LOG_DIR= ``` -The collector writes one trace file per run named -`libittnotify_refcol_.json`. It is a Chrome Trace Event trace in the -streaming-friendly "JSON Array Format", so it loads directly into +The collector writes one output file per run in the log directory. The file name +and contents depend on the selected mode (see below). + +## Output modes + +The output mode is controlled by the `EXP_LIBITTNOTIFY_GEN_JSON` environment +variable: + +| `EXP_LIBITTNOTIFY_GEN_JSON` | Mode | Output file | +|-----------------------------|-------------|-----------------------------------------| +| unset or `0` (default) | Text log | `libittnotify_refcol_.log` | +| `1` (or any non-zero value) | JSON trace | `libittnotify_refcol_.json` | + +**On Linux / FreeBSD** + +``` +export EXP_LIBITTNOTIFY_GEN_JSON=1 +``` + +**On Windows** + +``` +set EXP_LIBITTNOTIFY_GEN_JSON=1 +``` + +### Text log mode (default) + +Each ITT API call is written as a single human-readable line, for example: + +``` +[INFO] __itt_task_begin(...) - function args: domain=sample.app name=startup taskid=... +[INFO] __itt_domain_create(...) - function args: name=sample.app (created new domain) +``` + +### JSON trace mode + +When `EXP_LIBITTNOTIFY_GEN_JSON=1`, the collector writes a Chrome Trace Event +trace in the streaming-friendly "JSON Array Format", so it loads directly into or `chrome://tracing`. ITT API calls are mapped to trace events as follows: @@ -95,3 +139,8 @@ Each event carries an `itt_api` argument identifying the originating ITT call. Adding support for other ITT API calls is welcome: emit events with the `trace_emit()` helper, which takes a phase, category, name, timestamp, and an optional raw-JSON `extra` field (for `args`, `id`, `dur`, etc.). + +The two modes are kept as separate as possible within the single source file: +JSON emission lives in the `json_*` helper functions, while each ITT API entry +point dispatches to the JSON helper when `EXP_LIBITTNOTIFY_GEN_JSON` is set and +otherwise falls back to the plain-text logger. diff --git a/src/ittnotify_refcol/itt_refcol_impl.c b/src/ittnotify_refcol/itt_refcol_impl.c index 2387b7f2..6cdb86be 100644 --- a/src/ittnotify_refcol/itt_refcol_impl.c +++ b/src/ittnotify_refcol/itt_refcol_impl.c @@ -12,6 +12,9 @@ #include #ifndef _WIN32 #include +#if defined(__linux__) +#include +#endif #endif #define INTEL_NO_MACRO_BODY @@ -21,16 +24,31 @@ #define LOG_BUFFER_MAX_SIZE 256 -static const char* env_log_dir = "INTEL_LIBITTNOTIFY_LOG_DIR"; +static const char* env_log_dir = "INTEL_LIBITTNOTIFY_LOG_DIR"; + +// The reference collector supports two output modes: +// mode 1 (default): a plain-text log with one line per ITT API call. +// mode 2: a Perfetto / Chrome Trace Event trace in JSON. +// Mode 2 is enabled by setting EXP_LIBITTNOTIFY_GEN_JSON to a non-zero value. +static const char* env_gen_json = "EXP_LIBITTNOTIFY_GEN_JSON"; + +// Selected output mode: 0 = plain-text logging (default), 1 = JSON trace. +static int g_gen_json = 0; + +// Plain-text logger (mode 1) log levels. +static const char* log_level_str[] = {"INFO", "WARN", "ERROR", "FATAL_ERROR"}; + +enum { + LOG_LVL_INFO, + LOG_LVL_WARN, + LOG_LVL_ERROR, + LOG_LVL_FATAL +}; -// The collector emits a Perfetto / Chrome Trace Event trace in the streaming -// friendly "JSON Array Format": the file is a single JSON array of event -// objects. It can be opened directly in https://ui.perfetto.dev or -// chrome://tracing. static struct ref_collector_logger { FILE* log_fp; uint8_t init_state; - uint8_t first_event; // false once the first event has been written (controls comma separators) + uint8_t first_event; // JSON mode only: false once first event written (controls comma separators) } g_ref_collector_logger = {NULL, 0, 1}; // Collector maintains its own object lists instead of relying on __itt_global*, @@ -52,7 +70,7 @@ static struct ref_collector_global { #define REFCOL_LOCALTIME(out_tm, in_time) (localtime_r((in_time), (out_tm)) != NULL) #endif -static char* log_file_name_generate() +static char* log_file_name_generate(const char* ext) { time_t time_now = time(NULL); struct tm time_info; @@ -71,23 +89,28 @@ static char* log_file_name_generate() return NULL; } - snprintf(log_file_name, LOG_BUFFER_MAX_SIZE/2, "libittnotify_refcol_%d%d%d%d%d%d.json", + snprintf(log_file_name, LOG_BUFFER_MAX_SIZE/2, "libittnotify_refcol_%d%d%d%d%d%d.%s", time_info.tm_year+1900, time_info.tm_mon+1, time_info.tm_mday, - time_info.tm_hour, time_info.tm_min, time_info.tm_sec); + time_info.tm_hour, time_info.tm_min, time_info.tm_sec, ext); return log_file_name; } -// This reference implementation opens a log file for recording ITT API calls. -// Custom collectors can replace this with their own initialization logic -// (e.g., opening trace files, connecting to profiler backends, allocating buffers). +// This reference implementation opens an output file for recording ITT API calls. +// The output format (plain-text log vs JSON trace) is chosen from the +// EXP_LIBITTNOTIFY_GEN_JSON environment variable. Custom collectors can replace +// this with their own initialization logic (e.g., opening trace files, +// connecting to profiler backends, allocating buffers). static void ref_collector_init() { if (!g_ref_collector_logger.init_state) { static char file_name_buffer[LOG_BUFFER_MAX_SIZE*2]; + char* gen_json = getenv(env_gen_json); + g_gen_json = (gen_json != NULL && atoi(gen_json) != 0); + char* log_dir = getenv(env_log_dir); - char* log_file = log_file_name_generate(); + char* log_file = log_file_name_generate(g_gen_json ? "json" : "log"); if (log_dir != NULL) { @@ -115,16 +138,20 @@ static void ref_collector_init() } free(log_file); - g_ref_collector_logger.log_fp = fopen(file_name_buffer, "w"); + // JSON traces are truncated per run ("w"); plain logs are appended ("a"). + g_ref_collector_logger.log_fp = fopen(file_name_buffer, g_gen_json ? "w" : "a"); if (!g_ref_collector_logger.log_fp) { - printf("ERROR: Cannot open trace file: %s\n", file_name_buffer); + printf("ERROR: Cannot open output file: %s\n", file_name_buffer); return; } - // Open the Chrome Trace Event JSON array. - fprintf(g_ref_collector_logger.log_fp, "[\n"); - g_ref_collector_logger.first_event = 1; + if (g_gen_json) + { + // Open the Chrome Trace Event JSON array. + fprintf(g_ref_collector_logger.log_fp, "[\n"); + g_ref_collector_logger.first_event = 1; + } g_ref_collector_logger.init_state = 1; } } @@ -157,8 +184,11 @@ static void ref_collector_release(void) if (g_ref_collector_logger.log_fp) { - // Close the Chrome Trace Event JSON array. - fprintf(g_ref_collector_logger.log_fp, "\n]\n"); + if (g_gen_json) + { + // Close the Chrome Trace Event JSON array. + fprintf(g_ref_collector_logger.log_fp, "\n]\n"); + } fclose(g_ref_collector_logger.log_fp); g_ref_collector_logger.log_fp = NULL; } @@ -279,7 +309,7 @@ ITT_EXTERN_C void ITTAPI __itt_api_init(__itt_global* p, __itt_group_id init_gro } // ---------------------------------------------------------------------------- -// Perfetto / Chrome Trace Event writer +// Mode 2 backend: Perfetto / Chrome Trace Event writer // // Every instrumented ITT API call is translated into one or more trace events // and appended to the JSON array opened in ref_collector_init(). The resulting @@ -314,9 +344,23 @@ static uint64_t get_timestamp_us(void) static int get_process_id(void) { return (int)getpid(); } #endif +// Return a small OS-level thread id. Perfetto / chrome://tracing expect the +// numeric kernel thread id (as reported by perf, ftrace, gettid), not the +// large opaque pthread_t handle. Using the raw pthread_self() value here would +// make the UI collapse every thread into a single "main thread" track. static unsigned long long get_thread_id(void) { +#if defined(_WIN32) + return (unsigned long long)GetCurrentThreadId(); +#elif defined(__linux__) + return (unsigned long long)syscall(SYS_gettid); +#elif defined(__APPLE__) + uint64_t tid = 0; + pthread_threadid_np(NULL, &tid); + return (unsigned long long)tid; +#else return (unsigned long long)(uintptr_t)__itt_thread_id(); +#endif } // Escape a string so it can be safely embedded inside a JSON string literal. @@ -504,6 +548,50 @@ static char* wchar2char(const wchar_t* wide_str) } #endif +// ---------------------------------------------------------------------------- +// Mode 1 backend: plain-text call logger +// +// Writes one human-readable line per instrumented ITT API call to a .log file. +// This is the original reference-collector behavior and is used by default +// (when EXP_LIBITTNOTIFY_GEN_JSON is unset or zero). +// ---------------------------------------------------------------------------- + +static void log_func_call(uint8_t log_level, const char* function_name, const char* message_format, ...) +{ + if (!g_ref_collector_logger.init_state || !g_ref_collector_logger.log_fp) + { + printf("ERROR: Failed to log function call\n"); + return; + } + + char log_buffer[LOG_BUFFER_MAX_SIZE]; + uint32_t result_len = 0; + va_list message_args; + + result_len += snprintf(log_buffer, LOG_BUFFER_MAX_SIZE, "[%s] %s(...) - ", log_level_str[log_level], function_name); + if (result_len >= LOG_BUFFER_MAX_SIZE) + result_len = LOG_BUFFER_MAX_SIZE - 1; + va_start(message_args, message_format); + vsnprintf(log_buffer + result_len, LOG_BUFFER_MAX_SIZE - result_len, message_format, message_args); + va_end(message_args); + + fprintf(g_ref_collector_logger.log_fp, "%s\n", log_buffer); +} + +#define LOG_FUNC_CALL_INFO(...) log_func_call(LOG_LVL_INFO, __FUNCTION__, __VA_ARGS__) +#define LOG_FUNC_CALL_WARN(...) log_func_call(LOG_LVL_WARN, __FUNCTION__, __VA_ARGS__) +#define LOG_FUNC_CALL_ERROR(...) log_func_call(LOG_LVL_ERROR, __FUNCTION__, __VA_ARGS__) +#define LOG_FUNC_CALL_FATAL(...) log_func_call(LOG_LVL_FATAL, __FUNCTION__, __VA_ARGS__) + +// ---------------------------------------------------------------------------- +// ITT API entry points +// +// Each entry point validates its arguments, performs any shared bookkeeping +// (e.g. object-list management), then dispatches to the selected backend: +// the JSON writer (mode 2) when g_gen_json is set, otherwise the plain-text +// logger (mode 1). +// ---------------------------------------------------------------------------- + #ifdef _WIN32 ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_createW(const wchar_t *name) { @@ -519,6 +607,7 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) { if (!g_ref_collector_global.mutex_initialized || name == NULL) { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create domain object"); return NULL; } @@ -534,6 +623,11 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) if (h == NULL) { NEW_DOMAIN_A(&g_ref_collector_global, h, h_tail, name); + if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: name=%s (created new domain)", name); + } + else if (!g_gen_json) + { + LOG_FUNC_CALL_INFO("function args: name=%s (domain already exists)", name); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -556,6 +650,7 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* { if (!g_ref_collector_global.mutex_initialized || name == NULL) { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create string handle object"); return NULL; } @@ -571,6 +666,11 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* if (h == NULL) { NEW_STRING_HANDLE_A(&g_ref_collector_global, h, h_tail, name); + if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: name=%s (created new string handle)", name); + } + else if (!g_gen_json) + { + LOG_FUNC_CALL_INFO("function args: name=%s (string handle already exists)", name); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -593,6 +693,7 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_createA(const char *name, const ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create(const char *name, const char *domain) #endif { + if (!g_gen_json) LOG_FUNC_CALL_INFO("function call"); return __itt_counter_create_typed(name, domain, __itt_metadata_u64); } @@ -616,8 +717,10 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_v3( { if (domain == NULL) { + if (!g_gen_json) LOG_FUNC_CALL_WARN("domain is NULL"); return NULL; } + if (!g_gen_json) LOG_FUNC_CALL_INFO("function call"); return __itt_counter_create_typed(name, domain->nameA, type); } @@ -641,6 +744,7 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( { if (!g_ref_collector_global.mutex_initialized || name == NULL || domain == NULL) { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create counter object"); return NULL; } @@ -658,6 +762,13 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( if (h == NULL) { NEW_COUNTER_A(&g_ref_collector_global, h, h_tail, name, domain, type); + if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: name=%s, domain=%s, type=%d (created new counter)", + name, domain, (int)type); + } + else if (!g_gen_json) + { + LOG_FUNC_CALL_INFO("function args: name=%s, domain=%s, type=%d (counter already exists)", + name, domain, (int)type); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -683,6 +794,7 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( { if (!g_ref_collector_global.mutex_initialized || name == NULL || domain == NULL) { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create histogram object"); return NULL; } @@ -698,6 +810,13 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( if (h == NULL) { NEW_HISTOGRAM_A(&g_ref_collector_global, h, h_tail, domain, name, x_type, y_type); + if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: domain=%s, name=%s, x_type=%d, y_type=%d (created new histogram)", + domain->nameA, name, x_type, y_type); + } + else if (!g_gen_json) + { + LOG_FUNC_CALL_INFO("function args: domain=%s, name=%s, x_type=%d, y_type=%d (histogram already exists)", + domain->nameA, name, x_type, y_type); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -705,13 +824,19 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( return h; } -ITT_EXTERN_C void ITTAPI __itt_pause(void) +static void json_pause(void) { trace_emit("i", "itt", "__itt_pause", get_timestamp_us(), ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_pause\"}"); } -ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) +ITT_EXTERN_C void ITTAPI __itt_pause(void) +{ + if (g_gen_json) { json_pause(); return; } + LOG_FUNC_CALL_INFO("function call"); +} + +static void json_pause_scoped(__itt_collection_scope scope) { char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), @@ -719,13 +844,25 @@ ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) trace_emit("i", "itt", "__itt_pause_scoped", get_timestamp_us(), extra); } -ITT_EXTERN_C void ITTAPI __itt_resume(void) +ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) +{ + if (g_gen_json) { json_pause_scoped(scope); return; } + LOG_FUNC_CALL_INFO("function args: scope=%d", scope); +} + +static void json_resume(void) { trace_emit("i", "itt", "__itt_resume", get_timestamp_us(), ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_resume\"}"); } -ITT_EXTERN_C void ITTAPI __itt_resume_scoped(__itt_collection_scope scope) +ITT_EXTERN_C void ITTAPI __itt_resume(void) +{ + if (g_gen_json) { json_resume(); return; } + LOG_FUNC_CALL_INFO("function call"); +} + +static void json_resume_scoped(__itt_collection_scope scope) { char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), @@ -733,16 +870,57 @@ ITT_EXTERN_C void ITTAPI __itt_resume_scoped(__itt_collection_scope scope) trace_emit("i", "itt", "__itt_resume_scoped", get_timestamp_us(), extra); } -ITT_EXTERN_C void ITTAPI __itt_detach(void) +ITT_EXTERN_C void ITTAPI __itt_resume_scoped(__itt_collection_scope scope) +{ + if (g_gen_json) { json_resume_scoped(scope); return; } + LOG_FUNC_CALL_INFO("function args: scope=%d", scope); +} + +static void json_detach(void) { trace_emit("i", "itt", "__itt_detach", get_timestamp_us(), ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_detach\"}"); } -ITT_EXTERN_C void ITTAPI __itt_frame_begin_v3(const __itt_domain *domain, __itt_id *id) +ITT_EXTERN_C void ITTAPI __itt_detach(void) +{ + if (g_gen_json) { json_detach(); return; } + LOG_FUNC_CALL_INFO("function call"); +} + +// Emit a Chrome/Perfetto "thread_name" metadata (M) event so the calling +// thread's track is labeled in the UI (mode 2 only). +static void emit_thread_name(const char* name) { - if (domain == NULL) return; + if (name == NULL) return; + char name_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(name, name_esc, sizeof(name_esc)); + + char extra[LOG_BUFFER_MAX_SIZE * 2]; + snprintf(extra, sizeof(extra), ",\"args\":{\"name\":\"%s\"}", name_esc); + trace_emit("M", "__metadata", "thread_name", get_timestamp_us(), extra); +} + +#ifdef _WIN32 +ITT_EXTERN_C void ITTAPI __itt_thread_set_nameW(const wchar_t *name) +{ + if (!g_gen_json) return; // mode 1: not logged (matches original behavior) + char* name_a = wchar2char(name); + emit_thread_name(name_a); + free(name_a); +} +ITT_EXTERN_C void ITTAPI __itt_thread_set_nameA(const char *name) +#else +ITT_EXTERN_C void ITTAPI __itt_thread_set_name(const char *name) +#endif +{ + if (g_gen_json) emit_thread_name(name); + // mode 1: not logged (matches original behavior) +} + +static void json_frame_begin_v3(const __itt_domain *domain, __itt_id *id) +{ unsigned long long fid = (id != NULL) ? id->d1 : 0; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), @@ -750,10 +928,20 @@ ITT_EXTERN_C void ITTAPI __itt_frame_begin_v3(const __itt_domain *domain, __itt_ trace_emit("b", domain->nameA, domain->nameA, get_timestamp_us(), extra); } -ITT_EXTERN_C void ITTAPI __itt_frame_end_v3(const __itt_domain *domain, __itt_id *id) +ITT_EXTERN_C void ITTAPI __itt_frame_begin_v3(const __itt_domain *domain, __itt_id *id) { - if (domain == NULL) return; + if (domain == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_frame_begin_v3(domain, id); return; } + (void)id; + LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); +} +static void json_frame_end_v3(const __itt_domain *domain, __itt_id *id) +{ unsigned long long fid = (id != NULL) ? id->d1 : 0; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), @@ -761,12 +949,21 @@ ITT_EXTERN_C void ITTAPI __itt_frame_end_v3(const __itt_domain *domain, __itt_id trace_emit("e", domain->nameA, domain->nameA, get_timestamp_us(), extra); } -ITT_EXTERN_C void ITTAPI __itt_frame_submit_v3(const __itt_domain *domain, __itt_id *id, - __itt_timestamp begin, __itt_timestamp end) +ITT_EXTERN_C void ITTAPI __itt_frame_end_v3(const __itt_domain *domain, __itt_id *id) { - if (domain == NULL) return; - + if (domain == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_frame_end_v3(domain, id); return; } (void)id; + LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); +} + +static void json_frame_submit_v3(const __itt_domain *domain, + __itt_timestamp begin, __itt_timestamp end) +{ uint64_t dur = (end > begin) ? (uint64_t)(end - begin) : 0; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), @@ -776,11 +973,23 @@ ITT_EXTERN_C void ITTAPI __itt_frame_submit_v3(const __itt_domain *domain, __itt trace_emit("X", domain->nameA, domain->nameA, (uint64_t)begin, extra); } -ITT_EXTERN_C void ITTAPI __itt_task_begin( - const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) +ITT_EXTERN_C void ITTAPI __itt_frame_submit_v3(const __itt_domain *domain, __itt_id *id, + __itt_timestamp begin, __itt_timestamp end) { - if (domain == NULL || name == NULL) return; + if (domain == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + (void)id; + if (g_gen_json) { json_frame_submit_v3(domain, begin, end); return; } + LOG_FUNC_CALL_INFO("function args: domain=%s, time_begin=%llu, time_end=%llu", + domain->nameA, begin, end); +} +static void json_task_begin( + const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) +{ char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), ",\"args\":{\"itt_api\":\"__itt_task_begin\"," @@ -790,42 +999,86 @@ ITT_EXTERN_C void ITTAPI __itt_task_begin( trace_emit("B", domain->nameA, name->strA, get_timestamp_us(), extra); } -ITT_EXTERN_C void ITTAPI __itt_task_end(const __itt_domain *domain) +ITT_EXTERN_C void ITTAPI __itt_task_begin( + const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) { - if (domain == NULL) return; + if (domain == NULL || name == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_task_begin(domain, taskid, parentid, name); return; } + LOG_FUNC_CALL_INFO("function args: domain=%s name=%s taskid=%llu,%llu,%llu parentid=%llu,%llu,%llu", + domain->nameA, name->strA, + taskid.d1, taskid.d2, taskid.d3, + parentid.d1, parentid.d2, parentid.d3); +} +static void json_task_end(const __itt_domain *domain) +{ trace_emit("E", domain->nameA, "", get_timestamp_us(), ",\"args\":{\"itt_api\":\"__itt_task_end\"}"); } -ITT_EXTERN_C void ITTAPI __itt_region_begin( - const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) +ITT_EXTERN_C void ITTAPI __itt_task_end(const __itt_domain *domain) { - if (domain == NULL || name == NULL) return; + if (domain == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_task_end(domain); return; } + LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); +} - (void)parentid; +static void json_region_begin( + const __itt_domain *domain, __itt_id id, __itt_string_handle *name) +{ char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_region_begin\"}", id.d1); trace_emit("b", domain->nameA, name->strA, get_timestamp_us(), extra); } -ITT_EXTERN_C void ITTAPI __itt_region_end(const __itt_domain *domain, __itt_id id) +ITT_EXTERN_C void ITTAPI __itt_region_begin( + const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) { - if (domain == NULL) return; + if (domain == NULL || name == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + (void)parentid; + if (g_gen_json) { json_region_begin(domain, id, name); return; } + LOG_FUNC_CALL_INFO("function args: domain=%s name=%s id=%llu,%llu,%llu parentid=%llu,%llu,%llu", + domain->nameA, name->strA, + id.d1, id.d2, id.d3, + parentid.d1, parentid.d2, parentid.d3); +} +static void json_region_end(const __itt_domain *domain, __itt_id id) +{ char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_region_end\"}", id.d1); trace_emit("e", domain->nameA, "", get_timestamp_us(), extra); } -ITT_EXTERN_C void __itt_metadata_add(const __itt_domain *domain, __itt_id id, - __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) +ITT_EXTERN_C void ITTAPI __itt_region_end(const __itt_domain *domain, __itt_id id) { - if (domain == NULL || count == 0) return; + if (domain == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_region_end(domain, id); return; } + LOG_FUNC_CALL_INFO("function args: domain=%s id=%llu,%llu,%llu", + domain->nameA, id.d1, id.d2, id.d3); +} - (void)id; +static void json_metadata_add(const __itt_domain *domain, + __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) +{ char* metadata_str = get_metadata_elements(count, type, data); char key_esc[LOG_BUFFER_MAX_SIZE]; char data_esc[LOG_BUFFER_MAX_SIZE]; @@ -842,16 +1095,25 @@ ITT_EXTERN_C void __itt_metadata_add(const __itt_domain *domain, __itt_id id, free(metadata_str); } -ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt_string_handle *format, ...) +ITT_EXTERN_C void __itt_metadata_add(const __itt_domain *domain, __itt_id id, + __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) { - if (domain == NULL || format == NULL) return; - - va_list args; - va_start(args, format); - char formatted_metadata[LOG_BUFFER_MAX_SIZE]; - vsnprintf(formatted_metadata, LOG_BUFFER_MAX_SIZE, format->strA, args); - va_end(args); + if (domain == NULL || count == 0) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + (void)id; + if (g_gen_json) { json_metadata_add(domain, key, type, count, data); return; } + (void)key; + char* metadata_str = get_metadata_elements(count, type, data); + LOG_FUNC_CALL_INFO("function args: domain=%s metadata_size=%zu metadata[]=%s", + domain->nameA, count, metadata_str); + free(metadata_str); +} +static void json_formatted_metadata_add(const __itt_domain *domain, const char* formatted_metadata) +{ char data_esc[LOG_BUFFER_MAX_SIZE]; json_escape(formatted_metadata, data_esc, sizeof(data_esc)); @@ -862,14 +1124,27 @@ ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt trace_emit("i", domain->nameA, "__itt_formatted_metadata_add", get_timestamp_us(), extra); } -ITT_EXTERN_C void __itt_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) +ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt_string_handle *format, ...) { - if (hist == NULL || hist->domain == NULL || hist->domain->nameA == NULL || - hist->nameA == NULL || length == 0 || y_data == NULL) + if (domain == NULL || format == NULL) { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); return; } + va_list args; + va_start(args, format); + char formatted_metadata[LOG_BUFFER_MAX_SIZE]; + vsnprintf(formatted_metadata, LOG_BUFFER_MAX_SIZE, format->strA, args); + va_end(args); + + if (g_gen_json) { json_formatted_metadata_add(domain, formatted_metadata); return; } + LOG_FUNC_CALL_INFO("function args: domain=%s formatted_metadata=%s", + domain->nameA, formatted_metadata); +} + +static void json_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) +{ char* y_str = get_metadata_elements(length, hist->y_type, y_data); char y_esc[LOG_BUFFER_MAX_SIZE]; json_escape(y_str, y_esc, sizeof(y_esc)); @@ -897,10 +1172,43 @@ ITT_EXTERN_C void __itt_histogram_submit(__itt_histogram* hist, size_t length, v trace_emit("i", hist->domain->nameA, hist->nameA, get_timestamp_us(), extra); } -ITT_EXTERN_C void __itt_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +ITT_EXTERN_C void __itt_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) { - if (counter == NULL || metadata == NULL || length == 0) return; + if (hist == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Histogram is NULL"); + return; + } + if (hist->domain == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Histogram domain is NULL"); + return; + } + if (hist->domain->nameA == NULL || hist->nameA == NULL || length == 0 || y_data == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_histogram_submit(hist, length, x_data, y_data); return; } + + char* y_str = get_metadata_elements(length, hist->y_type, y_data); + if (x_data != NULL) + { + char* x_str = get_metadata_elements(length, hist->x_type, x_data); + LOG_FUNC_CALL_INFO("function args: histogram_name=%s length=%zu x_data[]=%s y_data[]=%s", + hist->nameA, length, x_str, y_str); + free(x_str); + } + else + { + LOG_FUNC_CALL_INFO("function args: histogram_name=%s length=%zu y_data[]=%s", + hist->nameA, length, y_str); + } + free(y_str); +} +static void json_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +{ __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; char context_metadata[LOG_BUFFER_MAX_SIZE]; context_metadata[0] = '\0'; @@ -924,10 +1232,31 @@ ITT_EXTERN_C void __itt_bind_context_metadata_to_counter(__itt_counter counter, get_timestamp_us(), extra); } -ITT_EXTERN_C void __itt_counter_set_value_v3(__itt_counter counter, void* value_ptr) +ITT_EXTERN_C void __itt_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) { - if (counter == NULL || value_ptr == NULL) return; + if (counter == NULL || metadata == NULL || length == 0) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_bind_context_metadata_to_counter(counter, length, metadata); return; } + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + char context_metadata[LOG_BUFFER_MAX_SIZE]; + context_metadata[0] = '\0'; + uint16_t offset = 0; + for (size_t i = 0; i < length && offset < LOG_BUFFER_MAX_SIZE - 1; i++) + { + char* elem = get_context_metadata_element(metadata[i].type, metadata[i].value); + offset += (uint16_t)snprintf(context_metadata + offset, LOG_BUFFER_MAX_SIZE - offset, "%s", elem); + free(elem); + } + LOG_FUNC_CALL_INFO("function args: counter_name=%s context_metadata_size=%zu context_metadata[]=%s", + (counter_info->nameA != NULL) ? counter_info->nameA : "", length, context_metadata); +} + +static void json_counter_set_value_v3(__itt_counter counter, void* value_ptr) +{ __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; uint64_t value = *(uint64_t*)value_ptr; const char* series = (counter_info->nameA != NULL) ? counter_info->nameA : "value"; @@ -939,3 +1268,18 @@ ITT_EXTERN_C void __itt_counter_set_value_v3(__itt_counter counter, void* value_ snprintf(extra, sizeof(extra), ",\"args\":{\"%s\":%" PRIu64 "}", series_esc, value); trace_emit("C", "counter", series, get_timestamp_us(), extra); } + +ITT_EXTERN_C void __itt_counter_set_value_v3(__itt_counter counter, void* value_ptr) +{ + if (counter == NULL || value_ptr == NULL) + { + if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + if (g_gen_json) { json_counter_set_value_v3(counter, value_ptr); return; } + + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + uint64_t value = *(uint64_t*)value_ptr; + LOG_FUNC_CALL_INFO("function args: counter_name=%s counter_value=%" PRIu64, + (counter_info->nameA != NULL) ? counter_info->nameA : "", value); +} From b34ee9cb12eb2e8eeaebfa086f83f522d2f4c03f Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Wed, 15 Jul 2026 10:47:24 -0500 Subject: [PATCH 03/10] update readme --- src/ittnotify_refcol/README.md | 79 +++++++++------------------------- 1 file changed, 21 insertions(+), 58 deletions(-) diff --git a/src/ittnotify_refcol/README.md b/src/ittnotify_refcol/README.md index c46f380a..da39b195 100644 --- a/src/ittnotify_refcol/README.md +++ b/src/ittnotify_refcol/README.md @@ -1,19 +1,7 @@ # Instrumentation and Tracing Technology (ITT) API Reference Collector -This is a reference implementation of the ITT API *dynamic* part. It records the -ITT API function calls made by an instrumented application and can produce the -output in one of two modes: - -1. **Text log (default)** — a human-readable `.log` file with one line per ITT - API call, describing the call and its arguments. -2. **JSON trace** — a - [Perfetto / Chrome Trace Event](https://ui.perfetto.dev) trace written in - JSON, which can be opened directly in or - `chrome://tracing`. - -The mode is selected with the `EXP_LIBITTNOTIFY_GEN_JSON` environment variable -(see [Output modes](#output-modes) below). By default the collector produces the -plain-text log. +This is a reference implementation of the ITT API *dynamic* part that +performs tracing data from ITT API function calls to log files. To use this solution, build the collector as a shared library and point the full library path to the `INTEL_LIBITTNOTIFY64` environment variable. @@ -66,7 +54,7 @@ setenv INTEL_LIBITTNOTIFY64 /libittnotify_refcol.so set INTEL_LIBITTNOTIFY64=\libittnotify_refcol.dll ``` -By default, trace files are saved in the system temporary directory. To change +By default, log files are saved in the system temporary directory. To change the location, use the `INTEL_LIBITTNOTIFY_LOG_DIR` environment variable: **On Linux** @@ -85,18 +73,24 @@ setenv INTEL_LIBITTNOTIFY_LOG_DIR set INTEL_LIBITTNOTIFY_LOG_DIR= ``` -The collector writes one output file per run in the log directory. The file name -and contents depend on the selected mode (see below). +This implementation adds logging of some of the ITT API function calls. Adding +logging of other ITT API function calls is welcome. The solution provides 4 +functions with different log levels that take `printf` format for logging: + +```c +LOG_FUNC_CALL_INFO(const char *msg_format, ...); +LOG_FUNC_CALL_WARN(const char *msg_format, ...); +LOG_FUNC_CALL_ERROR(const char *msg_format, ...); +LOG_FUNC_CALL_FATAL(const char *msg_format, ...); +``` -## Output modes +## Experimental: JSON trace generation -The output mode is controlled by the `EXP_LIBITTNOTIFY_GEN_JSON` environment -variable: +In addition to the default text log, the collector can produce a +[Perfetto / Chrome Trace Event](https://ui.perfetto.dev) trace in JSON format. +This mode is experimental and is disabled by default. -| `EXP_LIBITTNOTIFY_GEN_JSON` | Mode | Output file | -|-----------------------------|-------------|-----------------------------------------| -| unset or `0` (default) | Text log | `libittnotify_refcol_.log` | -| `1` (or any non-zero value) | JSON trace | `libittnotify_refcol_.json` | +To enable it, set the `EXP_LIBITTNOTIFY_GEN_JSON` environment variable to `1`: **On Linux / FreeBSD** @@ -110,37 +104,6 @@ export EXP_LIBITTNOTIFY_GEN_JSON=1 set EXP_LIBITTNOTIFY_GEN_JSON=1 ``` -### Text log mode (default) - -Each ITT API call is written as a single human-readable line, for example: - -``` -[INFO] __itt_task_begin(...) - function args: domain=sample.app name=startup taskid=... -[INFO] __itt_domain_create(...) - function args: name=sample.app (created new domain) -``` - -### JSON trace mode - -When `EXP_LIBITTNOTIFY_GEN_JSON=1`, the collector writes a Chrome Trace Event -trace in the streaming-friendly "JSON Array Format", so it loads directly into - or `chrome://tracing`. ITT API calls are mapped to -trace events as follows: - -| ITT API | Trace event phase | -|-----------------------------|--------------------------------------------| -| `__itt_task_begin` / `_end` | `B` / `E` (synchronous, per-thread) | -| `__itt_region_begin`/`_end` | `b` / `e` (asynchronous, matched by id) | -| `__itt_frame_begin`/`_end` | `b` / `e` (asynchronous, matched by id) | -| `__itt_frame_submit_v3` | `X` (complete event with explicit duration)| -| `__itt_counter_set_value` | `C` (counter series) | -| metadata / pause / resume | `i` (thread-scoped instant marker) | - -Each event carries an `itt_api` argument identifying the originating ITT call. -Adding support for other ITT API calls is welcome: emit events with the -`trace_emit()` helper, which takes a phase, category, name, timestamp, and an -optional raw-JSON `extra` field (for `args`, `id`, `dur`, etc.). - -The two modes are kept as separate as possible within the single source file: -JSON emission lives in the `json_*` helper functions, while each ITT API entry -point dispatches to the JSON helper when `EXP_LIBITTNOTIFY_GEN_JSON` is set and -otherwise falls back to the plain-text logger. +When enabled, the collector writes a `libittnotify_refcol_.json` file +(instead of the text log) into the log directory. The file can be opened +directly in or `chrome://tracing`. From 2fcd3bf204937224e4af950049a1951d2fbfbb18 Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Wed, 15 Jul 2026 11:01:38 -0500 Subject: [PATCH 04/10] cleanup --- src/ittnotify_refcol/tests/run_smoke_test.py | 34 ++++++-------------- 1 file changed, 9 insertions(+), 25 deletions(-) diff --git a/src/ittnotify_refcol/tests/run_smoke_test.py b/src/ittnotify_refcol/tests/run_smoke_test.py index ba245411..cea0c657 100644 --- a/src/ittnotify_refcol/tests/run_smoke_test.py +++ b/src/ittnotify_refcol/tests/run_smoke_test.py @@ -6,14 +6,13 @@ import argparse import glob -import json import os import subprocess import sys import tempfile -EXPECTED_ITT_APIS = [ +EXPECTED_SYMBOLS = [ "__itt_task_begin", "__itt_task_end", "__itt_metadata_add", @@ -53,36 +52,21 @@ def main(): print(f"ERROR: smoke test executable exited with code {result.returncode}") return 1 - logs = glob.glob(os.path.join(log_dir, "libittnotify_refcol_*.json")) + logs = glob.glob(os.path.join(log_dir, "libittnotify_refcol_*.log")) if not logs: - print("ERROR: no trace file found in", log_dir) + print("ERROR: no log file found in", log_dir) return 1 - trace_path = logs[0] - print(f"Trace file: {trace_path}") + log_path = logs[0] + print(f"Log file: {log_path}") - with open(trace_path, encoding="utf-8", errors="replace") as f: + with open(log_path, encoding="utf-8", errors="replace") as f: content = f.read() - try: - events = json.loads(content) - except json.JSONDecodeError as exc: - print(f"ERROR: trace file is not valid JSON: {exc}") - return 1 - - if not isinstance(events, list) or not events: - print("ERROR: trace file does not contain a non-empty JSON array of events") - return 1 - - seen_apis = { - e.get("args", {}).get("itt_api") - for e in events - if isinstance(e, dict) and isinstance(e.get("args"), dict) - } - missing = [api for api in EXPECTED_ITT_APIS if api not in seen_apis] + missing = [sym for sym in EXPECTED_SYMBOLS if sym not in content] if missing: - for api in missing: - print(f"ERROR: '{api}' event not found in trace") + for sym in missing: + print(f"ERROR: '{sym}' not found in log") return 1 print("Smoke test passed.") From 1e096e548b2079aa6c8c9e7826ced98d56899993 Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Thu, 16 Jul 2026 09:37:58 -0500 Subject: [PATCH 05/10] refactoring + extend smoke test --- src/ittnotify_refcol/itt_refcol_impl.c | 779 +++++++++++-------- src/ittnotify_refcol/tests/run_smoke_test.py | 138 +++- src/ittnotify_refcol/tests/smoke_test.c | 40 +- 3 files changed, 607 insertions(+), 350 deletions(-) diff --git a/src/ittnotify_refcol/itt_refcol_impl.c b/src/ittnotify_refcol/itt_refcol_impl.c index 6cdb86be..1ffafa67 100644 --- a/src/ittnotify_refcol/itt_refcol_impl.c +++ b/src/ittnotify_refcol/itt_refcol_impl.c @@ -70,7 +70,7 @@ static struct ref_collector_global { #define REFCOL_LOCALTIME(out_tm, in_time) (localtime_r((in_time), (out_tm)) != NULL) #endif -static char* log_file_name_generate(const char* ext) +static char* log_file_name_generate(void) { time_t time_now = time(NULL); struct tm time_info; @@ -89,9 +89,12 @@ static char* log_file_name_generate(const char* ext) return NULL; } - snprintf(log_file_name, LOG_BUFFER_MAX_SIZE/2, "libittnotify_refcol_%d%d%d%d%d%d.%s", - time_info.tm_year+1900, time_info.tm_mon+1, time_info.tm_mday, - time_info.tm_hour, time_info.tm_min, time_info.tm_sec, ext); + // Zero-padded, ordered timestamp (YYYYMMDD_HHMMSS) so file names sort + // chronologically and cannot collide between different dates/times. + char time_str[32]; + strftime(time_str, sizeof(time_str), "%Y%m%d_%H%M%S", &time_info); + snprintf(log_file_name, LOG_BUFFER_MAX_SIZE/2, "libittnotify_refcol_%s.%s", + time_str, g_gen_json ? "json" : "log"); return log_file_name; } @@ -110,7 +113,11 @@ static void ref_collector_init() g_gen_json = (gen_json != NULL && atoi(gen_json) != 0); char* log_dir = getenv(env_log_dir); - char* log_file = log_file_name_generate(g_gen_json ? "json" : "log"); + char* log_file = log_file_name_generate(); + if (log_file == NULL) + { + return; + } if (log_dir != NULL) { @@ -327,10 +334,14 @@ ITT_EXTERN_C void ITTAPI __itt_api_init(__itt_global* p, __itt_group_id init_gro #ifdef _WIN32 static uint64_t get_timestamp_us(void) { - LARGE_INTEGER freq, cnt; - QueryPerformanceFrequency(&freq); - QueryPerformanceCounter(&cnt); + // QueryPerformanceFrequency is fixed at system boot, so query it only once + // and reuse the cached value on every subsequent call. + static LARGE_INTEGER freq = {0}; + LARGE_INTEGER cnt; + if (freq.QuadPart == 0) + QueryPerformanceFrequency(&freq); if (freq.QuadPart == 0) return 0; + QueryPerformanceCounter(&cnt); return (uint64_t)((cnt.QuadPart * 1000000ULL) / (uint64_t)freq.QuadPart); } static int get_process_id(void) { return (int)GetCurrentProcessId(); } @@ -352,14 +363,8 @@ static unsigned long long get_thread_id(void) { #if defined(_WIN32) return (unsigned long long)GetCurrentThreadId(); -#elif defined(__linux__) - return (unsigned long long)syscall(SYS_gettid); -#elif defined(__APPLE__) - uint64_t tid = 0; - pthread_threadid_np(NULL, &tid); - return (unsigned long long)tid; #else - return (unsigned long long)(uintptr_t)__itt_thread_id(); + return (unsigned long long)syscall(SYS_gettid); #endif } @@ -399,7 +404,7 @@ static void json_escape(const char* src, char* dst, size_t dst_size) // Append a single trace event object to the JSON array. Thread-safe. // `extra` (may be NULL) is raw JSON appended after the mandatory fields, e.g. // ",\"dur\":123", ",\"id\":\"0x1\"", ",\"s\":\"t\"", ",\"args\":{...}". -static void trace_emit(const char* phase, const char* cat, const char* name, +static void json_write(const char* phase, const char* cat, const char* name, uint64_t ts, const char* extra) { if (!g_ref_collector_logger.init_state || !g_ref_collector_logger.log_fp) @@ -440,47 +445,54 @@ static void trace_emit(const char* phase, const char* cat, const char* name, static char* get_metadata_elements(size_t size, __itt_metadata_type type, void* metadata) { char* metadata_str = malloc(sizeof(char) * LOG_BUFFER_MAX_SIZE); - *metadata_str = '\0'; - uint16_t offset = 0; + if (metadata_str == NULL) return NULL; + metadata_str[0] = '\0'; + size_t offset = 0; + + // Bounded append into metadata_str: snprintf returns the number of chars it + // *would* have written, so clamp by the remaining space to make sure offset + // never runs past the buffer (and stop on encoding errors / when full). + #define APPEND_METADATA(fmt, val) \ + do { \ + if (offset >= LOG_BUFFER_MAX_SIZE - 1) break; \ + int _n = snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, \ + fmt ";", (val)); \ + if (_n < 0) break; \ + offset += ((size_t)_n < LOG_BUFFER_MAX_SIZE - offset) \ + ? (size_t)_n : (LOG_BUFFER_MAX_SIZE - offset - 1); \ + } while (0) switch (type) { case __itt_metadata_u64: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%" PRIu64 ";", ((uint64_t*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%" PRIu64, ((uint64_t*)metadata)[i]); break; case __itt_metadata_s64: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%" PRId64 ";", ((int64_t*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%" PRId64, ((int64_t*)metadata)[i]); break; case __itt_metadata_u32: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%u;", ((uint32_t*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%u", ((uint32_t*)metadata)[i]); break; case __itt_metadata_s32: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%d;", ((int32_t*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%d", ((int32_t*)metadata)[i]); break; case __itt_metadata_u16: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%u;", ((uint16_t*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%u", ((uint16_t*)metadata)[i]); break; case __itt_metadata_s16: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%d;", ((int16_t*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%d", ((int16_t*)metadata)[i]); break; case __itt_metadata_float: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%f;", ((float*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%f", ((float*)metadata)[i]); break; case __itt_metadata_double: - for (uint16_t i = 0; i < size && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - offset += snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, "%lf;", ((double*)metadata)[i]); + for (size_t i = 0; i < size; i++) APPEND_METADATA("%lf", ((double*)metadata)[i]); break; default: printf("ERROR: Unknown metadata type\n"); break; } + #undef APPEND_METADATA return metadata_str; } @@ -488,7 +500,8 @@ static char* get_metadata_elements(size_t size, __itt_metadata_type type, void* // Remember to call free() after using get_context_metadata_element() static char* get_context_metadata_element(__itt_context_type type, void* metadata) { - char* metadata_str = malloc(sizeof(char) * LOG_BUFFER_MAX_SIZE/4); + char* metadata_str = malloc(sizeof(char) * (LOG_BUFFER_MAX_SIZE/4)); + if (metadata_str == NULL) return NULL; *metadata_str = '\0'; switch(type) @@ -518,6 +531,25 @@ static char* get_context_metadata_element(__itt_context_type type, void* metadat return metadata_str; } +// Concatenate context-metadata elements into `buf` (bounded by `cap`). Shared by +// the JSON and plain-text handlers of __itt_bind_context_metadata_to_counter. +// snprintf's return value is clamped so `offset` never runs past the buffer. +static void build_context_metadata_str(char* buf, size_t cap, size_t length, __itt_context_metadata* metadata) +{ + if (cap == 0) return; + buf[0] = '\0'; + size_t offset = 0; + for (size_t i = 0; i < length && offset < cap - 1; i++) + { + char* elem = get_context_metadata_element(metadata[i].type, metadata[i].value); + if (elem == NULL) break; + int n = snprintf(buf + offset, cap - offset, "%s", elem); + free(elem); + if (n < 0) break; + offset += ((size_t)n < cap - offset) ? (size_t)n : (cap - offset - 1); + } +} + #ifdef _WIN32 static char* wchar2char(const wchar_t* wide_str) { @@ -578,11 +610,43 @@ static void log_func_call(uint8_t log_level, const char* function_name, const ch fprintf(g_ref_collector_logger.log_fp, "%s\n", log_buffer); } -#define LOG_FUNC_CALL_INFO(...) log_func_call(LOG_LVL_INFO, __FUNCTION__, __VA_ARGS__) +// Log a successful ITT API call. The uniform "function call" / "function args:" +// wording lives here instead of at every call site: with no variadic arguments +// the line reads "(...) - function call"; with a printf-style format +// (+args) it reads "(...) - function args: ". +static void log_api_call(uint8_t log_level, const char* function_name, const char* args_format, ...) +{ + if (args_format == NULL || args_format[0] == '\0') + { + log_func_call(log_level, function_name, "function call"); + return; + } + + char formatted[LOG_BUFFER_MAX_SIZE]; + va_list message_args; + va_start(message_args, args_format); + vsnprintf(formatted, sizeof(formatted), args_format, message_args); + va_end(message_args); + + log_func_call(log_level, function_name, "function args: %s", formatted); +} + +// INFO logs record a successful call and go through log_api_call(), so callers +// pass only the argument format (or nothing) - the "function call" / +// "function args:" boilerplate is added automatically. The empty-string default +// ("" __VA_ARGS__) makes the format optional for the argument-less case. +// WARN/ERROR/FATAL logs carry a custom message and go through log_func_call() +// verbatim. +#define LOG_FUNC_CALL_INFO(...) log_api_call(LOG_LVL_INFO, __FUNCTION__, "" __VA_ARGS__) #define LOG_FUNC_CALL_WARN(...) log_func_call(LOG_LVL_WARN, __FUNCTION__, __VA_ARGS__) #define LOG_FUNC_CALL_ERROR(...) log_func_call(LOG_LVL_ERROR, __FUNCTION__, __VA_ARGS__) #define LOG_FUNC_CALL_FATAL(...) log_func_call(LOG_LVL_FATAL, __FUNCTION__, __VA_ARGS__) +// Same as LOG_FUNC_CALL_* but with an explicit ITT API name. Used by the grouped +// log_* handlers below, whose own __FUNCTION__ is not the traced ITT API name. +#define LOG_CALL_INFO(api, ...) log_api_call(LOG_LVL_INFO, (api), "" __VA_ARGS__) +#define LOG_CALL_WARN(api, ...) log_func_call(LOG_LVL_WARN, (api), __VA_ARGS__) + // ---------------------------------------------------------------------------- // ITT API entry points // @@ -623,11 +687,11 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) if (h == NULL) { NEW_DOMAIN_A(&g_ref_collector_global, h, h_tail, name); - if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: name=%s (created new domain)", name); + if (!g_gen_json) LOG_FUNC_CALL_INFO("name=%s (created new domain)", name); } else if (!g_gen_json) { - LOG_FUNC_CALL_INFO("function args: name=%s (domain already exists)", name); + LOG_FUNC_CALL_INFO("name=%s (domain already exists)", name); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -666,11 +730,11 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* if (h == NULL) { NEW_STRING_HANDLE_A(&g_ref_collector_global, h, h_tail, name); - if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: name=%s (created new string handle)", name); + if (!g_gen_json) LOG_FUNC_CALL_INFO("name=%s (created new string handle)", name); } else if (!g_gen_json) { - LOG_FUNC_CALL_INFO("function args: name=%s (string handle already exists)", name); + LOG_FUNC_CALL_INFO("name=%s (string handle already exists)", name); } __itt_mutex_unlock(&g_ref_collector_global.mutex); @@ -693,7 +757,7 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_createA(const char *name, const ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create(const char *name, const char *domain) #endif { - if (!g_gen_json) LOG_FUNC_CALL_INFO("function call"); + // Thin wrapper: __itt_counter_create_typed() emits the single log line. return __itt_counter_create_typed(name, domain, __itt_metadata_u64); } @@ -720,7 +784,7 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_v3( if (!g_gen_json) LOG_FUNC_CALL_WARN("domain is NULL"); return NULL; } - if (!g_gen_json) LOG_FUNC_CALL_INFO("function call"); + // Thin wrapper: __itt_counter_create_typed() emits the single log line. return __itt_counter_create_typed(name, domain->nameA, type); } @@ -762,12 +826,12 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( if (h == NULL) { NEW_COUNTER_A(&g_ref_collector_global, h, h_tail, name, domain, type); - if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: name=%s, domain=%s, type=%d (created new counter)", + if (!g_gen_json) LOG_FUNC_CALL_INFO("name=%s, domain=%s, type=%d (created new counter)", name, domain, (int)type); } else if (!g_gen_json) { - LOG_FUNC_CALL_INFO("function args: name=%s, domain=%s, type=%d (counter already exists)", + LOG_FUNC_CALL_INFO("name=%s, domain=%s, type=%d (counter already exists)", name, domain, (int)type); } @@ -810,12 +874,12 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( if (h == NULL) { NEW_HISTOGRAM_A(&g_ref_collector_global, h, h_tail, domain, name, x_type, y_type); - if (!g_gen_json) LOG_FUNC_CALL_INFO("function args: domain=%s, name=%s, x_type=%d, y_type=%d (created new histogram)", + if (!g_gen_json) LOG_FUNC_CALL_INFO("domain=%s, name=%s, x_type=%d, y_type=%d (created new histogram)", domain->nameA, name, x_type, y_type); } else if (!g_gen_json) { - LOG_FUNC_CALL_INFO("function args: domain=%s, name=%s, x_type=%d, y_type=%d (histogram already exists)", + LOG_FUNC_CALL_INFO("domain=%s, name=%s, x_type=%d, y_type=%d (histogram already exists)", domain->nameA, name, x_type, y_type); } @@ -824,73 +888,51 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( return h; } -static void json_pause(void) -{ - trace_emit("i", "itt", "__itt_pause", get_timestamp_us(), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_pause\"}"); -} +// ---------------------------------------------------------------------------- +// Mode 2 event handlers (JSON) +// +// One json_* handler per traced ITT API call; every handler writes through +// json_write(). Argument validation lives inside each handler so the ITT entry +// points (further below) can stay as thin one-line dispatchers. +// ---------------------------------------------------------------------------- -ITT_EXTERN_C void ITTAPI __itt_pause(void) +static void json_pause(void) { - if (g_gen_json) { json_pause(); return; } - LOG_FUNC_CALL_INFO("function call"); + json_write("i", "itt", "__itt_pause", get_timestamp_us(), + ",\"s\":\"t\",\"args\":{\"api\":\"pause\"}"); } static void json_pause_scoped(__itt_collection_scope scope) { char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_pause_scoped\",\"scope\":%d}", (int)scope); - trace_emit("i", "itt", "__itt_pause_scoped", get_timestamp_us(), extra); -} - -ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) -{ - if (g_gen_json) { json_pause_scoped(scope); return; } - LOG_FUNC_CALL_INFO("function args: scope=%d", scope); + ",\"s\":\"t\",\"args\":{\"api\":\"pause\",\"scope\":%d}", (int)scope); + json_write("i", "itt", "__itt_pause_scoped", get_timestamp_us(), extra); } static void json_resume(void) { - trace_emit("i", "itt", "__itt_resume", get_timestamp_us(), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_resume\"}"); -} - -ITT_EXTERN_C void ITTAPI __itt_resume(void) -{ - if (g_gen_json) { json_resume(); return; } - LOG_FUNC_CALL_INFO("function call"); + json_write("i", "itt", "__itt_resume", get_timestamp_us(), + ",\"s\":\"t\",\"args\":{\"api\":\"resume\"}"); } static void json_resume_scoped(__itt_collection_scope scope) { char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_resume_scoped\",\"scope\":%d}", (int)scope); - trace_emit("i", "itt", "__itt_resume_scoped", get_timestamp_us(), extra); -} - -ITT_EXTERN_C void ITTAPI __itt_resume_scoped(__itt_collection_scope scope) -{ - if (g_gen_json) { json_resume_scoped(scope); return; } - LOG_FUNC_CALL_INFO("function args: scope=%d", scope); + ",\"s\":\"t\",\"args\":{\"api\":\"resume\",\"scope\":%d}", (int)scope); + json_write("i", "itt", "__itt_resume_scoped", get_timestamp_us(), extra); } static void json_detach(void) { - trace_emit("i", "itt", "__itt_detach", get_timestamp_us(), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_detach\"}"); -} - -ITT_EXTERN_C void ITTAPI __itt_detach(void) -{ - if (g_gen_json) { json_detach(); return; } - LOG_FUNC_CALL_INFO("function call"); + json_write("i", "itt", "__itt_detach", get_timestamp_us(), + ",\"s\":\"t\",\"args\":{\"api\":\"detach\"}"); } // Emit a Chrome/Perfetto "thread_name" metadata (M) event so the calling -// thread's track is labeled in the UI (mode 2 only). -static void emit_thread_name(const char* name) +// thread's track is labeled in the UI. +static void json_thread_set_name(const char* name) { if (name == NULL) return; @@ -899,186 +941,85 @@ static void emit_thread_name(const char* name) char extra[LOG_BUFFER_MAX_SIZE * 2]; snprintf(extra, sizeof(extra), ",\"args\":{\"name\":\"%s\"}", name_esc); - trace_emit("M", "__metadata", "thread_name", get_timestamp_us(), extra); -} - -#ifdef _WIN32 -ITT_EXTERN_C void ITTAPI __itt_thread_set_nameW(const wchar_t *name) -{ - if (!g_gen_json) return; // mode 1: not logged (matches original behavior) - char* name_a = wchar2char(name); - emit_thread_name(name_a); - free(name_a); -} -ITT_EXTERN_C void ITTAPI __itt_thread_set_nameA(const char *name) -#else -ITT_EXTERN_C void ITTAPI __itt_thread_set_name(const char *name) -#endif -{ - if (g_gen_json) emit_thread_name(name); - // mode 1: not logged (matches original behavior) + json_write("M", "__metadata", "thread_name", get_timestamp_us(), extra); } static void json_frame_begin_v3(const __itt_domain *domain, __itt_id *id) { + if (domain == NULL) return; unsigned long long fid = (id != NULL) ? id->d1 : 0; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_frame_begin_v3\"}", fid); - trace_emit("b", domain->nameA, domain->nameA, get_timestamp_us(), extra); -} - -ITT_EXTERN_C void ITTAPI __itt_frame_begin_v3(const __itt_domain *domain, __itt_id *id) -{ - if (domain == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - if (g_gen_json) { json_frame_begin_v3(domain, id); return; } - (void)id; - LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); + ",\"id\":\"0x%llx\",\"args\":{\"api\":\"frame\"}", fid); + json_write("b", domain->nameA, domain->nameA, get_timestamp_us(), extra); } static void json_frame_end_v3(const __itt_domain *domain, __itt_id *id) { + if (domain == NULL) return; unsigned long long fid = (id != NULL) ? id->d1 : 0; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_frame_end_v3\"}", fid); - trace_emit("e", domain->nameA, domain->nameA, get_timestamp_us(), extra); -} - -ITT_EXTERN_C void ITTAPI __itt_frame_end_v3(const __itt_domain *domain, __itt_id *id) -{ - if (domain == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - if (g_gen_json) { json_frame_end_v3(domain, id); return; } - (void)id; - LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); + ",\"id\":\"0x%llx\",\"args\":{\"api\":\"frame\"}", fid); + json_write("e", domain->nameA, domain->nameA, get_timestamp_us(), extra); } static void json_frame_submit_v3(const __itt_domain *domain, __itt_timestamp begin, __itt_timestamp end) { + if (domain == NULL) return; uint64_t dur = (end > begin) ? (uint64_t)(end - begin) : 0; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"dur\":%" PRIu64 ",\"args\":{\"itt_api\":\"__itt_frame_submit_v3\"," + ",\"dur\":%" PRIu64 ",\"args\":{\"api\":\"frame\"," "\"time_begin\":%llu,\"time_end\":%llu}", dur, (unsigned long long)begin, (unsigned long long)end); - trace_emit("X", domain->nameA, domain->nameA, (uint64_t)begin, extra); -} - -ITT_EXTERN_C void ITTAPI __itt_frame_submit_v3(const __itt_domain *domain, __itt_id *id, - __itt_timestamp begin, __itt_timestamp end) -{ - if (domain == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - (void)id; - if (g_gen_json) { json_frame_submit_v3(domain, begin, end); return; } - LOG_FUNC_CALL_INFO("function args: domain=%s, time_begin=%llu, time_end=%llu", - domain->nameA, begin, end); + json_write("X", domain->nameA, domain->nameA, (uint64_t)begin, extra); } static void json_task_begin( const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) { + if (domain == NULL || name == NULL) return; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"args\":{\"itt_api\":\"__itt_task_begin\"," + ",\"args\":{\"api\":\"task\"," "\"taskid\":\"%llu,%llu,%llu\",\"parentid\":\"%llu,%llu,%llu\"}", taskid.d1, taskid.d2, taskid.d3, parentid.d1, parentid.d2, parentid.d3); - trace_emit("B", domain->nameA, name->strA, get_timestamp_us(), extra); -} - -ITT_EXTERN_C void ITTAPI __itt_task_begin( - const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) -{ - if (domain == NULL || name == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - if (g_gen_json) { json_task_begin(domain, taskid, parentid, name); return; } - LOG_FUNC_CALL_INFO("function args: domain=%s name=%s taskid=%llu,%llu,%llu parentid=%llu,%llu,%llu", - domain->nameA, name->strA, - taskid.d1, taskid.d2, taskid.d3, - parentid.d1, parentid.d2, parentid.d3); + json_write("B", domain->nameA, name->strA, get_timestamp_us(), extra); } static void json_task_end(const __itt_domain *domain) { - trace_emit("E", domain->nameA, "", get_timestamp_us(), - ",\"args\":{\"itt_api\":\"__itt_task_end\"}"); -} - -ITT_EXTERN_C void ITTAPI __itt_task_end(const __itt_domain *domain) -{ - if (domain == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - if (g_gen_json) { json_task_end(domain); return; } - LOG_FUNC_CALL_INFO("function args: domain=%s", domain->nameA); + if (domain == NULL) return; + json_write("E", domain->nameA, "", get_timestamp_us(), + ",\"args\":{\"api\":\"task\"}"); } static void json_region_begin( const __itt_domain *domain, __itt_id id, __itt_string_handle *name) { + if (domain == NULL || name == NULL) return; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_region_begin\"}", id.d1); - trace_emit("b", domain->nameA, name->strA, get_timestamp_us(), extra); -} - -ITT_EXTERN_C void ITTAPI __itt_region_begin( - const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) -{ - if (domain == NULL || name == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - (void)parentid; - if (g_gen_json) { json_region_begin(domain, id, name); return; } - LOG_FUNC_CALL_INFO("function args: domain=%s name=%s id=%llu,%llu,%llu parentid=%llu,%llu,%llu", - domain->nameA, name->strA, - id.d1, id.d2, id.d3, - parentid.d1, parentid.d2, parentid.d3); + ",\"id\":\"0x%llx\",\"args\":{\"api\":\"region\"}", id.d1); + json_write("b", domain->nameA, name->strA, get_timestamp_us(), extra); } static void json_region_end(const __itt_domain *domain, __itt_id id) { + if (domain == NULL) return; char extra[LOG_BUFFER_MAX_SIZE]; snprintf(extra, sizeof(extra), - ",\"id\":\"0x%llx\",\"args\":{\"itt_api\":\"__itt_region_end\"}", id.d1); - trace_emit("e", domain->nameA, "", get_timestamp_us(), extra); -} - -ITT_EXTERN_C void ITTAPI __itt_region_end(const __itt_domain *domain, __itt_id id) -{ - if (domain == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - if (g_gen_json) { json_region_end(domain, id); return; } - LOG_FUNC_CALL_INFO("function args: domain=%s id=%llu,%llu,%llu", - domain->nameA, id.d1, id.d2, id.d3); + ",\"id\":\"0x%llx\",\"args\":{\"api\":\"region\"}", id.d1); + json_write("e", domain->nameA, "", get_timestamp_us(), extra); } static void json_metadata_add(const __itt_domain *domain, __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) { + if (domain == NULL || count == 0) return; char* metadata_str = get_metadata_elements(count, type, data); char key_esc[LOG_BUFFER_MAX_SIZE]; char data_esc[LOG_BUFFER_MAX_SIZE]; @@ -1087,64 +1028,35 @@ static void json_metadata_add(const __itt_domain *domain, char extra[LOG_BUFFER_MAX_SIZE * 2]; snprintf(extra, sizeof(extra), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_metadata_add\"," + ",\"s\":\"t\",\"args\":{\"api\":\"metadata\"," "\"key\":\"%s\",\"count\":%zu,\"data\":\"%s\"}", key_esc, count, data_esc); - trace_emit("i", domain->nameA, (key != NULL) ? key->strA : "metadata", + json_write("i", domain->nameA, (key != NULL) ? key->strA : "metadata", get_timestamp_us(), extra); free(metadata_str); } -ITT_EXTERN_C void __itt_metadata_add(const __itt_domain *domain, __itt_id id, - __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) -{ - if (domain == NULL || count == 0) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - (void)id; - if (g_gen_json) { json_metadata_add(domain, key, type, count, data); return; } - (void)key; - char* metadata_str = get_metadata_elements(count, type, data); - LOG_FUNC_CALL_INFO("function args: domain=%s metadata_size=%zu metadata[]=%s", - domain->nameA, count, metadata_str); - free(metadata_str); -} - static void json_formatted_metadata_add(const __itt_domain *domain, const char* formatted_metadata) { + if (domain == NULL) return; char data_esc[LOG_BUFFER_MAX_SIZE]; json_escape(formatted_metadata, data_esc, sizeof(data_esc)); char extra[LOG_BUFFER_MAX_SIZE * 2]; snprintf(extra, sizeof(extra), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_formatted_metadata_add\",\"data\":\"%s\"}", + ",\"s\":\"t\",\"args\":{\"api\":\"metadata\",\"data\":\"%s\"}", data_esc); - trace_emit("i", domain->nameA, "__itt_formatted_metadata_add", get_timestamp_us(), extra); + json_write("i", domain->nameA, "__itt_formatted_metadata_add", get_timestamp_us(), extra); } -ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt_string_handle *format, ...) +static void json_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) { - if (domain == NULL || format == NULL) + if (hist == NULL || hist->domain == NULL || hist->domain->nameA == NULL || + hist->nameA == NULL || length == 0 || y_data == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); return; } - va_list args; - va_start(args, format); - char formatted_metadata[LOG_BUFFER_MAX_SIZE]; - vsnprintf(formatted_metadata, LOG_BUFFER_MAX_SIZE, format->strA, args); - va_end(args); - - if (g_gen_json) { json_formatted_metadata_add(domain, formatted_metadata); return; } - LOG_FUNC_CALL_INFO("function args: domain=%s formatted_metadata=%s", - domain->nameA, formatted_metadata); -} - -static void json_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) -{ char* y_str = get_metadata_elements(length, hist->y_type, y_data); char y_esc[LOG_BUFFER_MAX_SIZE]; json_escape(y_str, y_esc, sizeof(y_esc)); @@ -1158,128 +1070,351 @@ static void json_histogram_submit(__itt_histogram* hist, size_t length, void* x_ json_escape(x_str, x_esc, sizeof(x_esc)); free(x_str); snprintf(extra, sizeof(extra), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_histogram_submit\"," + ",\"s\":\"t\",\"args\":{\"api\":\"histogram\"," "\"length\":%zu,\"x\":\"%s\",\"y\":\"%s\"}", length, x_esc, y_esc); } else { snprintf(extra, sizeof(extra), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_histogram_submit\"," + ",\"s\":\"t\",\"args\":{\"api\":\"histogram\"," "\"length\":%zu,\"y\":\"%s\"}", length, y_esc); } - trace_emit("i", hist->domain->nameA, hist->nameA, get_timestamp_us(), extra); + json_write("i", hist->domain->nameA, hist->nameA, get_timestamp_us(), extra); } -ITT_EXTERN_C void __itt_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) +static void json_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) { - if (hist == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Histogram is NULL"); - return; - } - if (hist->domain == NULL) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Histogram domain is NULL"); - return; - } + if (counter == NULL || metadata == NULL || length == 0) return; + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + char context_metadata[LOG_BUFFER_MAX_SIZE]; + build_context_metadata_str(context_metadata, sizeof(context_metadata), length, metadata); + + char ctx_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(context_metadata, ctx_esc, sizeof(ctx_esc)); + + char extra[LOG_BUFFER_MAX_SIZE * 2]; + snprintf(extra, sizeof(extra), + ",\"s\":\"t\",\"args\":{\"api\":\"counter\"," + "\"length\":%zu,\"context\":\"%s\"}", + length, ctx_esc); + json_write("i", "counter", (counter_info->nameA != NULL) ? counter_info->nameA : "", + get_timestamp_us(), extra); +} + +static void json_counter_set_value_v3(__itt_counter counter, void* value_ptr) +{ + if (counter == NULL || value_ptr == NULL) return; + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + uint64_t value = *(uint64_t*)value_ptr; + const char* series = (counter_info->nameA != NULL) ? counter_info->nameA : "value"; + + char series_esc[LOG_BUFFER_MAX_SIZE]; + json_escape(series, series_esc, sizeof(series_esc)); + + char extra[LOG_BUFFER_MAX_SIZE * 2]; + snprintf(extra, sizeof(extra), ",\"args\":{\"%s\":%" PRIu64 "}", series_esc, value); + json_write("C", "counter", series, get_timestamp_us(), extra); +} + +// ---------------------------------------------------------------------------- +// Mode 1 event handlers (plain-text log) +// +// One log_* handler per traced ITT API call, mirroring the json_* handlers +// above. Each writes a single human-readable line via the LOG_CALL_* macros +// (which take the explicit ITT API name). Argument validation lives here too. +// ---------------------------------------------------------------------------- + +static void log_pause(void) +{ + LOG_CALL_INFO("__itt_pause"); +} + +static void log_pause_scoped(__itt_collection_scope scope) +{ + LOG_CALL_INFO("__itt_pause_scoped", "scope=%d", scope); +} + +static void log_resume(void) +{ + LOG_CALL_INFO("__itt_resume"); +} + +static void log_resume_scoped(__itt_collection_scope scope) +{ + LOG_CALL_INFO("__itt_resume_scoped", "scope=%d", scope); +} + +static void log_detach(void) +{ + LOG_CALL_INFO("__itt_detach"); +} + +static void log_frame_begin_v3(const __itt_domain *domain, __itt_id *id) +{ + (void)id; + if (domain == NULL) { LOG_CALL_WARN("__itt_frame_begin_v3", "Incorrect function call"); return; } + LOG_CALL_INFO("__itt_frame_begin_v3", "domain=%s", domain->nameA); +} + +static void log_frame_end_v3(const __itt_domain *domain, __itt_id *id) +{ + (void)id; + if (domain == NULL) { LOG_CALL_WARN("__itt_frame_end_v3", "Incorrect function call"); return; } + LOG_CALL_INFO("__itt_frame_end_v3", "domain=%s", domain->nameA); +} + +static void log_frame_submit_v3(const __itt_domain *domain, __itt_timestamp begin, __itt_timestamp end) +{ + if (domain == NULL) { LOG_CALL_WARN("__itt_frame_submit_v3", "Incorrect function call"); return; } + LOG_CALL_INFO("__itt_frame_submit_v3", "domain=%s, time_begin=%llu, time_end=%llu", + domain->nameA, begin, end); +} + +static void log_task_begin(const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) +{ + if (domain == NULL || name == NULL) { LOG_CALL_WARN("__itt_task_begin", "Incorrect function call"); return; } + LOG_CALL_INFO("__itt_task_begin", "domain=%s name=%s taskid=%llu,%llu,%llu parentid=%llu,%llu,%llu", + domain->nameA, name->strA, + taskid.d1, taskid.d2, taskid.d3, + parentid.d1, parentid.d2, parentid.d3); +} + +static void log_task_end(const __itt_domain *domain) +{ + if (domain == NULL) { LOG_CALL_WARN("__itt_task_end", "Incorrect function call"); return; } + LOG_CALL_INFO("__itt_task_end", "domain=%s", domain->nameA); +} + +static void log_region_begin(const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) +{ + if (domain == NULL || name == NULL) { LOG_CALL_WARN("__itt_region_begin", "Incorrect function call"); return; } + LOG_CALL_INFO("__itt_region_begin", "domain=%s name=%s id=%llu,%llu,%llu parentid=%llu,%llu,%llu", + domain->nameA, name->strA, + id.d1, id.d2, id.d3, + parentid.d1, parentid.d2, parentid.d3); +} + +static void log_region_end(const __itt_domain *domain, __itt_id id) +{ + if (domain == NULL) { LOG_CALL_WARN("__itt_region_end", "Incorrect function call"); return; } + LOG_CALL_INFO("__itt_region_end", "domain=%s id=%llu,%llu,%llu", + domain->nameA, id.d1, id.d2, id.d3); +} + +static void log_metadata_add(const __itt_domain *domain, __itt_metadata_type type, size_t count, void *data) +{ + if (domain == NULL || count == 0) { LOG_CALL_WARN("__itt_metadata_add", "Incorrect function call"); return; } + char* metadata_str = get_metadata_elements(count, type, data); + LOG_CALL_INFO("__itt_metadata_add", "domain=%s metadata_size=%zu metadata[]=%s", + domain->nameA, count, metadata_str); + free(metadata_str); +} + +static void log_formatted_metadata_add(const __itt_domain *domain, const char* formatted_metadata) +{ + LOG_CALL_INFO("__itt_formatted_metadata_add", "domain=%s formatted_metadata=%s", + domain->nameA, formatted_metadata); +} + +static void log_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) +{ + if (hist == NULL) { LOG_CALL_WARN("__itt_histogram_submit", "Histogram is NULL"); return; } + if (hist->domain == NULL) { LOG_CALL_WARN("__itt_histogram_submit", "Histogram domain is NULL"); return; } if (hist->domain->nameA == NULL || hist->nameA == NULL || length == 0 || y_data == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + LOG_CALL_WARN("__itt_histogram_submit", "Incorrect function call"); return; } - if (g_gen_json) { json_histogram_submit(hist, length, x_data, y_data); return; } - char* y_str = get_metadata_elements(length, hist->y_type, y_data); if (x_data != NULL) { char* x_str = get_metadata_elements(length, hist->x_type, x_data); - LOG_FUNC_CALL_INFO("function args: histogram_name=%s length=%zu x_data[]=%s y_data[]=%s", - hist->nameA, length, x_str, y_str); + LOG_CALL_INFO("__itt_histogram_submit", "histogram_name=%s length=%zu x_data[]=%s y_data[]=%s", + hist->nameA, length, x_str, y_str); free(x_str); } else { - LOG_FUNC_CALL_INFO("function args: histogram_name=%s length=%zu y_data[]=%s", - hist->nameA, length, y_str); + LOG_CALL_INFO("__itt_histogram_submit", "histogram_name=%s length=%zu y_data[]=%s", + hist->nameA, length, y_str); } free(y_str); } -static void json_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +static void log_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) { + if (counter == NULL || metadata == NULL || length == 0) + { + LOG_CALL_WARN("__itt_bind_context_metadata_to_counter", "Incorrect function call"); + return; + } __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; char context_metadata[LOG_BUFFER_MAX_SIZE]; - context_metadata[0] = '\0'; - uint16_t offset = 0; - for (size_t i = 0; i < length && offset < LOG_BUFFER_MAX_SIZE - 1; i++) + build_context_metadata_str(context_metadata, sizeof(context_metadata), length, metadata); + LOG_CALL_INFO("__itt_bind_context_metadata_to_counter", + "counter_name=%s context_metadata_size=%zu context_metadata[]=%s", + (counter_info->nameA != NULL) ? counter_info->nameA : "", length, context_metadata); +} + +static void log_counter_set_value_v3(__itt_counter counter, void* value_ptr) +{ + if (counter == NULL || value_ptr == NULL) { - char* elem = get_context_metadata_element(metadata[i].type, metadata[i].value); - offset += (uint16_t)snprintf(context_metadata + offset, LOG_BUFFER_MAX_SIZE - offset, "%s", elem); - free(elem); + LOG_CALL_WARN("__itt_counter_set_value_v3", "Incorrect function call"); + return; } + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + uint64_t value = *(uint64_t*)value_ptr; + LOG_CALL_INFO("__itt_counter_set_value_v3", "counter_name=%s counter_value=%" PRIu64, + (counter_info->nameA != NULL) ? counter_info->nameA : "", value); +} - char ctx_esc[LOG_BUFFER_MAX_SIZE]; - json_escape(context_metadata, ctx_esc, sizeof(ctx_esc)); +// ---------------------------------------------------------------------------- +// ITT API entry points (traced events) +// +// Thin dispatchers: select the plain-text logger (mode 1) or the JSON writer +// (mode 2) based on g_gen_json. All validation and formatting lives in the +// matching log_* / json_* handlers above. +// ---------------------------------------------------------------------------- - char extra[LOG_BUFFER_MAX_SIZE * 2]; - snprintf(extra, sizeof(extra), - ",\"s\":\"t\",\"args\":{\"itt_api\":\"__itt_bind_context_metadata_to_counter\"," - "\"length\":%zu,\"context\":\"%s\"}", - length, ctx_esc); - trace_emit("i", "counter", (counter_info->nameA != NULL) ? counter_info->nameA : "", - get_timestamp_us(), extra); +ITT_EXTERN_C void ITTAPI __itt_pause(void) +{ + if (!g_gen_json) log_pause(); + else json_pause(); } -ITT_EXTERN_C void __itt_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) { - if (counter == NULL || metadata == NULL || length == 0) - { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); - return; - } - if (g_gen_json) { json_bind_context_metadata_to_counter(counter, length, metadata); return; } + if (!g_gen_json) log_pause_scoped(scope); + else json_pause_scoped(scope); +} - __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; - char context_metadata[LOG_BUFFER_MAX_SIZE]; - context_metadata[0] = '\0'; - uint16_t offset = 0; - for (size_t i = 0; i < length && offset < LOG_BUFFER_MAX_SIZE - 1; i++) - { - char* elem = get_context_metadata_element(metadata[i].type, metadata[i].value); - offset += (uint16_t)snprintf(context_metadata + offset, LOG_BUFFER_MAX_SIZE - offset, "%s", elem); - free(elem); - } - LOG_FUNC_CALL_INFO("function args: counter_name=%s context_metadata_size=%zu context_metadata[]=%s", - (counter_info->nameA != NULL) ? counter_info->nameA : "", length, context_metadata); +ITT_EXTERN_C void ITTAPI __itt_resume(void) +{ + if (!g_gen_json) log_resume(); + else json_resume(); } -static void json_counter_set_value_v3(__itt_counter counter, void* value_ptr) +ITT_EXTERN_C void ITTAPI __itt_resume_scoped(__itt_collection_scope scope) { - __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; - uint64_t value = *(uint64_t*)value_ptr; - const char* series = (counter_info->nameA != NULL) ? counter_info->nameA : "value"; + if (!g_gen_json) log_resume_scoped(scope); + else json_resume_scoped(scope); +} - char series_esc[LOG_BUFFER_MAX_SIZE]; - json_escape(series, series_esc, sizeof(series_esc)); +ITT_EXTERN_C void ITTAPI __itt_detach(void) +{ + if (!g_gen_json) log_detach(); + else json_detach(); +} - char extra[LOG_BUFFER_MAX_SIZE * 2]; - snprintf(extra, sizeof(extra), ",\"args\":{\"%s\":%" PRIu64 "}", series_esc, value); - trace_emit("C", "counter", series, get_timestamp_us(), extra); +// __itt_thread_set_name has no plain-text log realization: the original +// reference collector never logged it. In JSON mode it labels the thread track. +#ifdef _WIN32 +ITT_EXTERN_C void ITTAPI __itt_thread_set_nameW(const wchar_t *name) +{ + if (!g_gen_json) return; + char* name_a = wchar2char(name); + json_thread_set_name(name_a); + free(name_a); +} +ITT_EXTERN_C void ITTAPI __itt_thread_set_nameA(const char *name) +#else +ITT_EXTERN_C void ITTAPI __itt_thread_set_name(const char *name) +#endif +{ + if (g_gen_json) json_thread_set_name(name); } -ITT_EXTERN_C void __itt_counter_set_value_v3(__itt_counter counter, void* value_ptr) +ITT_EXTERN_C void ITTAPI __itt_frame_begin_v3(const __itt_domain *domain, __itt_id *id) { - if (counter == NULL || value_ptr == NULL) + if (!g_gen_json) log_frame_begin_v3(domain, id); + else json_frame_begin_v3(domain, id); +} + +ITT_EXTERN_C void ITTAPI __itt_frame_end_v3(const __itt_domain *domain, __itt_id *id) +{ + if (!g_gen_json) log_frame_end_v3(domain, id); + else json_frame_end_v3(domain, id); +} + +ITT_EXTERN_C void ITTAPI __itt_frame_submit_v3(const __itt_domain *domain, __itt_id *id, + __itt_timestamp begin, __itt_timestamp end) +{ + (void)id; + if (!g_gen_json) log_frame_submit_v3(domain, begin, end); + else json_frame_submit_v3(domain, begin, end); +} + +ITT_EXTERN_C void ITTAPI __itt_task_begin( + const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) +{ + if (!g_gen_json) log_task_begin(domain, taskid, parentid, name); + else json_task_begin(domain, taskid, parentid, name); +} + +ITT_EXTERN_C void ITTAPI __itt_task_end(const __itt_domain *domain) +{ + if (!g_gen_json) log_task_end(domain); + else json_task_end(domain); +} + +ITT_EXTERN_C void ITTAPI __itt_region_begin( + const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) +{ + if (!g_gen_json) log_region_begin(domain, id, parentid, name); + else json_region_begin(domain, id, name); +} + +ITT_EXTERN_C void ITTAPI __itt_region_end(const __itt_domain *domain, __itt_id id) +{ + if (!g_gen_json) log_region_end(domain, id); + else json_region_end(domain, id); +} + +ITT_EXTERN_C void __itt_metadata_add(const __itt_domain *domain, __itt_id id, + __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) +{ + (void)id; + if (!g_gen_json) log_metadata_add(domain, type, count, data); + else json_metadata_add(domain, key, type, count, data); +} + +ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt_string_handle *format, ...) +{ + // Formatting the variadic args must happen here (in the entry point) before + // dispatching, so validate up front too. + if (domain == NULL || format == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Incorrect function call"); + if (!g_gen_json) LOG_CALL_WARN("__itt_formatted_metadata_add", "Incorrect function call"); return; } - if (g_gen_json) { json_counter_set_value_v3(counter, value_ptr); return; } - __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; - uint64_t value = *(uint64_t*)value_ptr; - LOG_FUNC_CALL_INFO("function args: counter_name=%s counter_value=%" PRIu64, - (counter_info->nameA != NULL) ? counter_info->nameA : "", value); + va_list args; + va_start(args, format); + char formatted_metadata[LOG_BUFFER_MAX_SIZE]; + vsnprintf(formatted_metadata, LOG_BUFFER_MAX_SIZE, format->strA, args); + va_end(args); + + if (!g_gen_json) log_formatted_metadata_add(domain, formatted_metadata); + else json_formatted_metadata_add(domain, formatted_metadata); +} + +ITT_EXTERN_C void __itt_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) +{ + if (!g_gen_json) log_histogram_submit(hist, length, x_data, y_data); + else json_histogram_submit(hist, length, x_data, y_data); +} + +ITT_EXTERN_C void __itt_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +{ + if (!g_gen_json) log_bind_context_metadata_to_counter(counter, length, metadata); + else json_bind_context_metadata_to_counter(counter, length, metadata); +} + +ITT_EXTERN_C void __itt_counter_set_value_v3(__itt_counter counter, void* value_ptr) +{ + if (!g_gen_json) log_counter_set_value_v3(counter, value_ptr); + else json_counter_set_value_v3(counter, value_ptr); } diff --git a/src/ittnotify_refcol/tests/run_smoke_test.py b/src/ittnotify_refcol/tests/run_smoke_test.py index cea0c657..dae75df4 100644 --- a/src/ittnotify_refcol/tests/run_smoke_test.py +++ b/src/ittnotify_refcol/tests/run_smoke_test.py @@ -6,56 +6,58 @@ import argparse import glob +import json import os import subprocess import sys import tempfile +# ITT API names expected in the plain-text log (mode 1). EXPECTED_SYMBOLS = [ "__itt_task_begin", "__itt_task_end", "__itt_metadata_add", + "__itt_frame_begin_v3", + "__itt_frame_end_v3", + "__itt_region_begin", + "__itt_region_end", ] +# Friendly "api" values expected in the JSON trace args (mode 2). +EXPECTED_JSON_APIS = [ + "task", + "metadata", + "frame", + "region", +] -def main(): - parser = argparse.ArgumentParser(description="Run reference collector smoke test") - parser.add_argument("--lib", required=True, help="Path to libittnotify_refcol shared library") - parser.add_argument("--exe", required=True, help="Path to refcol_smoke_test executable") - parser.add_argument("--log-dir", help="Directory for log files (default: temp dir)") - args = parser.parse_args() - - lib = os.path.abspath(args.lib) - exe = os.path.abspath(args.exe) - - if not os.path.isfile(lib): - print(f"ERROR: library not found: {lib}") - return 1 - if not os.path.isfile(exe): - print(f"ERROR: executable not found: {exe}") - return 1 - log_dir = os.path.abspath(args.log_dir) if args.log_dir else tempfile.mkdtemp(prefix="refcol_logs_") - os.makedirs(log_dir, exist_ok=True) +def run_exe(exe, lib, log_dir, gen_json): + """Run the smoke test executable with the collector attached. + gen_json selects the collector output mode: False -> plain-text log, + True -> JSON trace (EXP_LIBITTNOTIFY_GEN_JSON=1). + """ env = os.environ.copy() env["INTEL_LIBITTNOTIFY64"] = lib env["INTEL_LIBITTNOTIFY_LOG_DIR"] = log_dir - - print(f"Library: {lib}") - print(f"Exe: {exe}") - print(f"Log dir: {log_dir}") + if gen_json: + env["EXP_LIBITTNOTIFY_GEN_JSON"] = "1" result = subprocess.run([exe], env=env) if result.returncode != 0: print(f"ERROR: smoke test executable exited with code {result.returncode}") - return 1 + return False + return True + +def check_text_log(log_dir): + """Scenario 1: plain-text log contains the expected ITT API call lines.""" logs = glob.glob(os.path.join(log_dir, "libittnotify_refcol_*.log")) if not logs: - print("ERROR: no log file found in", log_dir) - return 1 + print("ERROR: no .log file found in", log_dir) + return False log_path = logs[0] print(f"Log file: {log_path}") @@ -67,9 +69,93 @@ def main(): if missing: for sym in missing: print(f"ERROR: '{sym}' not found in log") + return False + + print("Text log scenario passed.") + return True + + +def check_json_trace(log_dir): + """Scenario 2: JSON trace is a valid Chrome Trace Event array with the + expected task events and friendly api arg values.""" + traces = glob.glob(os.path.join(log_dir, "libittnotify_refcol_*.json")) + if not traces: + print("ERROR: no .json file found in", log_dir) + return False + + trace_path = traces[0] + print(f"Trace file: {trace_path}") + + try: + with open(trace_path, encoding="utf-8", errors="replace") as f: + events = json.load(f) + except json.JSONDecodeError as exc: + print(f"ERROR: JSON trace is not valid JSON: {exc}") + return False + + if not isinstance(events, list) or not events: + print("ERROR: JSON trace is empty or not an array") + return False + + phases = {e.get("ph") for e in events} + if "B" not in phases or "E" not in phases: + print(f"ERROR: expected task begin/end (B/E) phases, got: {sorted(phases)}") + return False + + seen_apis = {e.get("args", {}).get("api") for e in events} + missing = [api for api in EXPECTED_JSON_APIS if api not in seen_apis] + if missing: + for api in missing: + print(f"ERROR: api '{api}' not found in JSON trace args") + return False + + print("JSON trace scenario passed.") + return True + + +def main(): + parser = argparse.ArgumentParser(description="Run reference collector smoke test") + parser.add_argument("--lib", required=True, help="Path to libittnotify_refcol shared library") + parser.add_argument("--exe", required=True, help="Path to refcol_smoke_test executable") + parser.add_argument("--log-dir", help="Base directory for log files (default: temp dir)") + args = parser.parse_args() + + lib = os.path.abspath(args.lib) + exe = os.path.abspath(args.exe) + + if not os.path.isfile(lib): + print(f"ERROR: library not found: {lib}") + return 1 + if not os.path.isfile(exe): + print(f"ERROR: executable not found: {exe}") + return 1 + + base_dir = os.path.abspath(args.log_dir) if args.log_dir else tempfile.mkdtemp(prefix="refcol_logs_") + + print(f"Library: {lib}") + print(f"Exe: {exe}") + print(f"Log dir: {base_dir}") + + # Each scenario writes to its own subdirectory so the .log and .json + # outputs do not mix. + text_dir = os.path.join(base_dir, "text") + json_dir = os.path.join(base_dir, "json") + os.makedirs(text_dir, exist_ok=True) + os.makedirs(json_dir, exist_ok=True) + + print("\n=== Scenario 1: plain-text log (default) ===") + if not run_exe(exe, lib, text_dir, gen_json=False): + return 1 + if not check_text_log(text_dir): + return 1 + + print("\n=== Scenario 2: JSON trace (EXP_LIBITTNOTIFY_GEN_JSON=1) ===") + if not run_exe(exe, lib, json_dir, gen_json=True): + return 1 + if not check_json_trace(json_dir): return 1 - print("Smoke test passed.") + print("\nSmoke test passed.") return 0 diff --git a/src/ittnotify_refcol/tests/smoke_test.c b/src/ittnotify_refcol/tests/smoke_test.c index 4c2a5bf9..8cbc8d2b 100644 --- a/src/ittnotify_refcol/tests/smoke_test.c +++ b/src/ittnotify_refcol/tests/smoke_test.c @@ -7,9 +7,10 @@ #include "ittnotify.h" #include "ittnotify_types.h" -int main(void) +/* Scenario 1: nested tasks with metadata attached, driven by a matrix + multiply. Exercises __itt_task_begin / __itt_metadata_add / __itt_task_end. */ +static void scenario_tasks_with_metadata(__itt_domain* domain) { - __itt_domain* domain = __itt_domain_create("smoke_test_domain"); __itt_string_handle* handle = __itt_string_handle_create("smoke_test_handler"); __itt_string_handle* handle_work = __itt_string_handle_create("smoke_test_worker"); @@ -38,6 +39,41 @@ int main(void) __itt_task_end(domain); } } +} + +/* Scenario 2: frames enclosing regions, with a counter updated per frame. + Exercises __itt_frame_begin_v3 / __itt_frame_end_v3, __itt_region_begin / + __itt_region_end and __itt_counter_create_v3 / __itt_counter_set_value_v3. */ +static void scenario_frames_regions_counter(__itt_domain* domain) +{ + __itt_string_handle* handle_region = __itt_string_handle_create("smoke_test_region"); + __itt_counter counter = __itt_counter_create_v3(domain, "smoke_test_counter", __itt_metadata_u64); + + const int frames = 4; + int f; + + for (f = 0; f < frames; f++) + { + __itt_id frame_id = __itt_id_make(domain, f); + __itt_frame_begin_v3(domain, &frame_id); + + __itt_id region_id = __itt_id_make(domain, frames + f); + __itt_region_begin(domain, region_id, __itt_null, handle_region); + + unsigned long long value = (unsigned long long)(f + 1); + __itt_counter_set_value_v3(counter, &value); + + __itt_region_end(domain, region_id); + __itt_frame_end_v3(domain, &frame_id); + } +} + +int main(void) +{ + __itt_domain* domain = __itt_domain_create("smoke_test_domain"); + + scenario_tasks_with_metadata(domain); + scenario_frames_regions_counter(domain); return 0; } From f8d4fa204b6a6ad35bec542708e487a8a96ff16e Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Fri, 17 Jul 2026 09:41:13 -0500 Subject: [PATCH 06/10] refactoring --- src/ittnotify_refcol/itt_refcol_impl.c | 665 ++++++++++++------------- 1 file changed, 322 insertions(+), 343 deletions(-) diff --git a/src/ittnotify_refcol/itt_refcol_impl.c b/src/ittnotify_refcol/itt_refcol_impl.c index 1ffafa67..1e7b8e90 100644 --- a/src/ittnotify_refcol/itt_refcol_impl.c +++ b/src/ittnotify_refcol/itt_refcol_impl.c @@ -25,18 +25,8 @@ #define LOG_BUFFER_MAX_SIZE 256 static const char* env_log_dir = "INTEL_LIBITTNOTIFY_LOG_DIR"; - -// The reference collector supports two output modes: -// mode 1 (default): a plain-text log with one line per ITT API call. -// mode 2: a Perfetto / Chrome Trace Event trace in JSON. -// Mode 2 is enabled by setting EXP_LIBITTNOTIFY_GEN_JSON to a non-zero value. -static const char* env_gen_json = "EXP_LIBITTNOTIFY_GEN_JSON"; - -// Selected output mode: 0 = plain-text logging (default), 1 = JSON trace. -static int g_gen_json = 0; - -// Plain-text logger (mode 1) log levels. static const char* log_level_str[] = {"INFO", "WARN", "ERROR", "FATAL_ERROR"}; +static const char* env_gen_json = "EXP_LIBITTNOTIFY_GEN_JSON"; enum { LOG_LVL_INFO, @@ -48,8 +38,9 @@ enum { static struct ref_collector_logger { FILE* log_fp; uint8_t init_state; - uint8_t first_event; // JSON mode only: false once first event written (controls comma separators) -} g_ref_collector_logger = {NULL, 0, 1}; + uint8_t first_event; + uint8_t gen_json; +} g_ref_collector_logger = {NULL, 0, 1, 0}; // Collector maintains its own object lists instead of relying on __itt_global*, // because traced apps may contain multiple static ITT parts, each with its own __itt_global*. @@ -70,7 +61,7 @@ static struct ref_collector_global { #define REFCOL_LOCALTIME(out_tm, in_time) (localtime_r((in_time), (out_tm)) != NULL) #endif -static char* log_file_name_generate(void) +static char* output_file_name_generate(void) { time_t time_now = time(NULL); struct tm time_info; @@ -89,31 +80,27 @@ static char* log_file_name_generate(void) return NULL; } - // Zero-padded, ordered timestamp (YYYYMMDD_HHMMSS) so file names sort - // chronologically and cannot collide between different dates/times. char time_str[32]; strftime(time_str, sizeof(time_str), "%Y%m%d_%H%M%S", &time_info); snprintf(log_file_name, LOG_BUFFER_MAX_SIZE/2, "libittnotify_refcol_%s.%s", - time_str, g_gen_json ? "json" : "log"); + time_str, g_ref_collector_logger.gen_json ? "json" : "log"); return log_file_name; } -// This reference implementation opens an output file for recording ITT API calls. -// The output format (plain-text log vs JSON trace) is chosen from the -// EXP_LIBITTNOTIFY_GEN_JSON environment variable. Custom collectors can replace -// this with their own initialization logic (e.g., opening trace files, -// connecting to profiler backends, allocating buffers). -static void ref_collector_init() +// This reference collector implementation opens an output file for recording ITT API calls. +// Custom collectors can replace this with their own initialization logic +// (e.g., opening trace files, connecting to profiler backends, allocating buffers). +static void ref_collector_init(void) { if (!g_ref_collector_logger.init_state) { static char file_name_buffer[LOG_BUFFER_MAX_SIZE*2]; char* gen_json = getenv(env_gen_json); - g_gen_json = (gen_json != NULL && atoi(gen_json) != 0); + g_ref_collector_logger.gen_json = (gen_json != NULL && atoi(gen_json) != 0); char* log_dir = getenv(env_log_dir); - char* log_file = log_file_name_generate(); + char* log_file = output_file_name_generate(); if (log_file == NULL) { return; @@ -145,17 +132,15 @@ static void ref_collector_init() } free(log_file); - // JSON traces are truncated per run ("w"); plain logs are appended ("a"). - g_ref_collector_logger.log_fp = fopen(file_name_buffer, g_gen_json ? "w" : "a"); + g_ref_collector_logger.log_fp = fopen(file_name_buffer, g_ref_collector_logger.gen_json ? "w" : "a"); if (!g_ref_collector_logger.log_fp) { printf("ERROR: Cannot open output file: %s\n", file_name_buffer); return; } - if (g_gen_json) + if (g_ref_collector_logger.gen_json) { - // Open the Chrome Trace Event JSON array. fprintf(g_ref_collector_logger.log_fp, "[\n"); g_ref_collector_logger.first_event = 1; } @@ -172,7 +157,7 @@ static void __itt_report_error(int code, ...) // Initialize the collector's mutex for thread-safe access to object lists. // Must be called before any ITT API functions that access the lists. -static void ref_collector_init_mutex() +static void ref_collector_init_mutex(void) { if (!g_ref_collector_global.mutex_initialized) { @@ -182,7 +167,7 @@ static void ref_collector_init_mutex() } // Cleanup hook called at program exit via atexit(). -// Releases all resources: closes log file, frees all ITT objects. +// Releases all resources: closes output file, frees all ITT objects. static void ref_collector_release(void) { static int released = 0; @@ -191,9 +176,8 @@ static void ref_collector_release(void) if (g_ref_collector_logger.log_fp) { - if (g_gen_json) + if (g_ref_collector_logger.gen_json) { - // Close the Chrome Trace Event JSON array. fprintf(g_ref_collector_logger.log_fp, "\n]\n"); } fclose(g_ref_collector_logger.log_fp); @@ -316,26 +300,12 @@ ITT_EXTERN_C void ITTAPI __itt_api_init(__itt_global* p, __itt_group_id init_gro } // ---------------------------------------------------------------------------- -// Mode 2 backend: Perfetto / Chrome Trace Event writer -// -// Every instrumented ITT API call is translated into one or more trace events -// and appended to the JSON array opened in ref_collector_init(). The resulting -// file loads directly in https://ui.perfetto.dev or chrome://tracing. -// -// Event phase mapping: -// task begin / end -> "B" / "E" (synchronous, per-thread, nestable) -// region begin / end -> "b" / "e" (asynchronous, matched by id) -// frame begin / end -> "b" / "e" (asynchronous, matched by id) -// frame submit -> "X" (complete event with explicit duration) -// counter set value -> "C" (counter series) -// everything else -> "i" (thread-scoped instant marker) +// The code section with a set of different utility helper functions. // ---------------------------------------------------------------------------- #ifdef _WIN32 static uint64_t get_timestamp_us(void) { - // QueryPerformanceFrequency is fixed at system boot, so query it only once - // and reuse the cached value on every subsequent call. static LARGE_INTEGER freq = {0}; LARGE_INTEGER cnt; if (freq.QuadPart == 0) @@ -344,7 +314,10 @@ static uint64_t get_timestamp_us(void) QueryPerformanceCounter(&cnt); return (uint64_t)((cnt.QuadPart * 1000000ULL) / (uint64_t)freq.QuadPart); } -static int get_process_id(void) { return (int)GetCurrentProcessId(); } +static int get_process_id(void) +{ + return (int)GetCurrentProcessId(); +} #else static uint64_t get_timestamp_us(void) { @@ -352,13 +325,12 @@ static uint64_t get_timestamp_us(void) clock_gettime(CLOCK_MONOTONIC, &ts); return (uint64_t)ts.tv_sec * 1000000ULL + (uint64_t)ts.tv_nsec / 1000ULL; } -static int get_process_id(void) { return (int)getpid(); } +static int get_process_id(void) +{ + return (int)getpid(); +} #endif -// Return a small OS-level thread id. Perfetto / chrome://tracing expect the -// numeric kernel thread id (as reported by perf, ftrace, gettid), not the -// large opaque pthread_t handle. Using the raw pthread_self() value here would -// make the UI collapse every thread into a single "main thread" track. static unsigned long long get_thread_id(void) { #if defined(_WIN32) @@ -401,9 +373,7 @@ static void json_escape(const char* src, char* dst, size_t dst_size) dst[j] = '\0'; } -// Append a single trace event object to the JSON array. Thread-safe. -// `extra` (may be NULL) is raw JSON appended after the mandatory fields, e.g. -// ",\"dur\":123", ",\"id\":\"0x1\"", ",\"s\":\"t\"", ",\"args\":{...}". +// Append a single trace event object to the JSON array. static void json_write(const char* phase, const char* cat, const char* name, uint64_t ts, const char* extra) { @@ -433,13 +403,16 @@ static void json_write(const char* phase, const char* cat, const char* name, __itt_mutex_unlock(&g_ref_collector_global.mutex); } -// ---------------------------------------------------------------------------- -// The code below is a reference implementation of the ITT API functions. -// These functions are bound to static parts via fill_func_ptr_per_lib() -// and log all ITT API calls to a file for reference/debugging purposes. -// In a real collector, these functions could save trace data to a file, -// forward events to a profiler, or perform any other instrumentation work. -// ---------------------------------------------------------------------------- +// Bounded append into metadata_str +#define APPEND_METADATA(fmt, val) \ + do { \ + if (offset >= LOG_BUFFER_MAX_SIZE - 1) break; \ + int _n = snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, \ + fmt ";", (val)); \ + if (_n < 0) break; \ + offset += ((size_t)_n < LOG_BUFFER_MAX_SIZE - offset) \ + ? (size_t)_n : (LOG_BUFFER_MAX_SIZE - offset - 1); \ + } while (0) // Remember to call free() after using get_metadata_elements() static char* get_metadata_elements(size_t size, __itt_metadata_type type, void* metadata) @@ -449,19 +422,6 @@ static char* get_metadata_elements(size_t size, __itt_metadata_type type, void* metadata_str[0] = '\0'; size_t offset = 0; - // Bounded append into metadata_str: snprintf returns the number of chars it - // *would* have written, so clamp by the remaining space to make sure offset - // never runs past the buffer (and stop on encoding errors / when full). - #define APPEND_METADATA(fmt, val) \ - do { \ - if (offset >= LOG_BUFFER_MAX_SIZE - 1) break; \ - int _n = snprintf(metadata_str + offset, LOG_BUFFER_MAX_SIZE - offset, \ - fmt ";", (val)); \ - if (_n < 0) break; \ - offset += ((size_t)_n < LOG_BUFFER_MAX_SIZE - offset) \ - ? (size_t)_n : (LOG_BUFFER_MAX_SIZE - offset - 1); \ - } while (0) - switch (type) { case __itt_metadata_u64: @@ -492,7 +452,6 @@ static char* get_metadata_elements(size_t size, __itt_metadata_type type, void* printf("ERROR: Unknown metadata type\n"); break; } - #undef APPEND_METADATA return metadata_str; } @@ -531,9 +490,7 @@ static char* get_context_metadata_element(__itt_context_type type, void* metadat return metadata_str; } -// Concatenate context-metadata elements into `buf` (bounded by `cap`). Shared by -// the JSON and plain-text handlers of __itt_bind_context_metadata_to_counter. -// snprintf's return value is clamped so `offset` never runs past the buffer. +// Concatenate context-metadata elements into `buf` (bounded by `cap`). static void build_context_metadata_str(char* buf, size_t cap, size_t length, __itt_context_metadata* metadata) { if (cap == 0) return; @@ -580,16 +537,14 @@ static char* wchar2char(const wchar_t* wide_str) } #endif -// ---------------------------------------------------------------------------- -// Mode 1 backend: plain-text call logger -// -// Writes one human-readable line per instrumented ITT API call to a .log file. -// This is the original reference-collector behavior and is used by default -// (when EXP_LIBITTNOTIFY_GEN_JSON is unset or zero). -// ---------------------------------------------------------------------------- - -static void log_func_call(uint8_t log_level, const char* function_name, const char* message_format, ...) +// Write one line per instrumented ITT API call to a .log file. +// No-op in JSON mode, so callers can log unconditionally. +static void log_func_call( + uint8_t log_level, const char* function_name, const char* message_format, ...) { + if (g_ref_collector_logger.gen_json) + return; + if (!g_ref_collector_logger.init_state || !g_ref_collector_logger.log_fp) { printf("ERROR: Failed to log function call\n"); @@ -600,22 +555,26 @@ static void log_func_call(uint8_t log_level, const char* function_name, const ch uint32_t result_len = 0; va_list message_args; - result_len += snprintf(log_buffer, LOG_BUFFER_MAX_SIZE, "[%s] %s(...) - ", log_level_str[log_level], function_name); + result_len += snprintf(log_buffer, LOG_BUFFER_MAX_SIZE, + "[%s] %s(...) - ", log_level_str[log_level], function_name); if (result_len >= LOG_BUFFER_MAX_SIZE) result_len = LOG_BUFFER_MAX_SIZE - 1; va_start(message_args, message_format); - vsnprintf(log_buffer + result_len, LOG_BUFFER_MAX_SIZE - result_len, message_format, message_args); + vsnprintf(log_buffer + result_len, LOG_BUFFER_MAX_SIZE - result_len, + message_format, message_args); va_end(message_args); fprintf(g_ref_collector_logger.log_fp, "%s\n", log_buffer); } -// Log a successful ITT API call. The uniform "function call" / "function args:" -// wording lives here instead of at every call site: with no variadic arguments -// the line reads "(...) - function call"; with a printf-style format -// (+args) it reads "(...) - function args: ". -static void log_api_call(uint8_t log_level, const char* function_name, const char* args_format, ...) +static void log_api_call( + uint8_t log_level, const char* function_name, const char* args_format, ...) { + if (g_ref_collector_logger.gen_json) + { + return; + } + if (args_format == NULL || args_format[0] == '\0') { log_func_call(log_level, function_name, "function call"); @@ -631,29 +590,35 @@ static void log_api_call(uint8_t log_level, const char* function_name, const cha log_func_call(log_level, function_name, "function args: %s", formatted); } -// INFO logs record a successful call and go through log_api_call(), so callers -// pass only the argument format (or nothing) - the "function call" / -// "function args:" boilerplate is added automatically. The empty-string default -// ("" __VA_ARGS__) makes the format optional for the argument-less case. -// WARN/ERROR/FATAL logs carry a custom message and go through log_func_call() -// verbatim. #define LOG_FUNC_CALL_INFO(...) log_api_call(LOG_LVL_INFO, __FUNCTION__, "" __VA_ARGS__) -#define LOG_FUNC_CALL_WARN(...) log_func_call(LOG_LVL_WARN, __FUNCTION__, __VA_ARGS__) -#define LOG_FUNC_CALL_ERROR(...) log_func_call(LOG_LVL_ERROR, __FUNCTION__, __VA_ARGS__) -#define LOG_FUNC_CALL_FATAL(...) log_func_call(LOG_LVL_FATAL, __FUNCTION__, __VA_ARGS__) - -// Same as LOG_FUNC_CALL_* but with an explicit ITT API name. Used by the grouped -// log_* handlers below, whose own __FUNCTION__ is not the traced ITT API name. -#define LOG_CALL_INFO(api, ...) log_api_call(LOG_LVL_INFO, (api), "" __VA_ARGS__) -#define LOG_CALL_WARN(api, ...) log_func_call(LOG_LVL_WARN, (api), __VA_ARGS__) +#define LOG_FUNC_CALL_WARN(...) log_func_call(LOG_LVL_WARN, __FUNCTION__, "" __VA_ARGS__) +#define LOG_FUNC_CALL_ERROR(...) log_func_call(LOG_LVL_ERROR, __FUNCTION__, "" __VA_ARGS__) +#define LOG_FUNC_CALL_FATAL(...) log_func_call(LOG_LVL_FATAL, __FUNCTION__, "" __VA_ARGS__) // ---------------------------------------------------------------------------- -// ITT API entry points +// The code below is a reference implementation of the ITT API tracing. +// The ITT API functions are bound to static parts via fill_func_ptr_per_lib() +// and trace all ITT API calls to a file for reference/debugging purposes. +// +// This reference collector implementation supports two output modes: +// +// - Mode 1 (default): plain-text call logger +// Writes one human-readable line per instrumented ITT API call to a .log file. +// This is the original reference-collector behavior and is used by default. // -// Each entry point validates its arguments, performs any shared bookkeeping -// (e.g. object-list management), then dispatches to the selected backend: -// the JSON writer (mode 2) when g_gen_json is set, otherwise the plain-text -// logger (mode 1). +// - Mode 2 (experimental): trace event writer in JSON format (Perfetto) +// (enabled by setting EXP_LIBITTNOTIFY_GEN_JSON to a non-zero value) +// Every instrumented ITT API call is translated into one or more trace events +// and appended to the JSON array opened in ref_collector_init(). The resulting +// file could be loaded in https://ui.perfetto.dev. +// +// Event phase mapping: +// task begin / end -> "B" / "E" (synchronous, per-thread, nestable) +// region begin / end -> "b" / "e" (asynchronous, matched by id) +// frame begin / end -> "b" / "e" (asynchronous, matched by id) +// frame submit -> "X" (complete event with explicit duration) +// counter set value -> "C" (counter series) +// everything else -> "i" (thread-scoped instant marker) // ---------------------------------------------------------------------------- #ifdef _WIN32 @@ -671,7 +636,7 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) { if (!g_ref_collector_global.mutex_initialized || name == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create domain object"); + LOG_FUNC_CALL_WARN("Cannot create domain object"); return NULL; } @@ -687,9 +652,9 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) if (h == NULL) { NEW_DOMAIN_A(&g_ref_collector_global, h, h_tail, name); - if (!g_gen_json) LOG_FUNC_CALL_INFO("name=%s (created new domain)", name); + LOG_FUNC_CALL_INFO("name=%s (created new domain)", name); } - else if (!g_gen_json) + else { LOG_FUNC_CALL_INFO("name=%s (domain already exists)", name); } @@ -714,7 +679,7 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* { if (!g_ref_collector_global.mutex_initialized || name == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create string handle object"); + LOG_FUNC_CALL_WARN("Cannot create string handle object"); return NULL; } @@ -730,9 +695,9 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* if (h == NULL) { NEW_STRING_HANDLE_A(&g_ref_collector_global, h, h_tail, name); - if (!g_gen_json) LOG_FUNC_CALL_INFO("name=%s (created new string handle)", name); + LOG_FUNC_CALL_INFO("name=%s (created new string handle)", name); } - else if (!g_gen_json) + else { LOG_FUNC_CALL_INFO("name=%s (string handle already exists)", name); } @@ -757,7 +722,6 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_createA(const char *name, const ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create(const char *name, const char *domain) #endif { - // Thin wrapper: __itt_counter_create_typed() emits the single log line. return __itt_counter_create_typed(name, domain, __itt_metadata_u64); } @@ -781,10 +745,9 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_v3( { if (domain == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("domain is NULL"); + LOG_FUNC_CALL_WARN("domain is NULL"); return NULL; } - // Thin wrapper: __itt_counter_create_typed() emits the single log line. return __itt_counter_create_typed(name, domain->nameA, type); } @@ -808,7 +771,7 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( { if (!g_ref_collector_global.mutex_initialized || name == NULL || domain == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create counter object"); + LOG_FUNC_CALL_WARN("Cannot create counter object"); return NULL; } @@ -826,10 +789,10 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( if (h == NULL) { NEW_COUNTER_A(&g_ref_collector_global, h, h_tail, name, domain, type); - if (!g_gen_json) LOG_FUNC_CALL_INFO("name=%s, domain=%s, type=%d (created new counter)", + LOG_FUNC_CALL_INFO("name=%s, domain=%s, type=%d (created new counter)", name, domain, (int)type); } - else if (!g_gen_json) + else { LOG_FUNC_CALL_INFO("name=%s, domain=%s, type=%d (counter already exists)", name, domain, (int)type); @@ -841,24 +804,24 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( } #ifdef _WIN32 -ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_createW( - const __itt_domain* domain, const wchar_t* name, __itt_metadata_type x_type, __itt_metadata_type y_type) +ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_createW(const __itt_domain* domain, + const wchar_t* name, __itt_metadata_type x_type, __itt_metadata_type y_type) { char* name_a = wchar2char(name); __itt_histogram* result = __itt_histogram_createA(domain, name_a, x_type, y_type); free(name_a); return result; } -ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_createA( - const __itt_domain* domain, const char* name, __itt_metadata_type x_type, __itt_metadata_type y_type) +ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_createA(const __itt_domain* domain, + const char* name, __itt_metadata_type x_type, __itt_metadata_type y_type) #else -ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( - const __itt_domain* domain, const char* name, __itt_metadata_type x_type, __itt_metadata_type y_type) +ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create(const __itt_domain* domain, + const char* name, __itt_metadata_type x_type, __itt_metadata_type y_type) #endif { if (!g_ref_collector_global.mutex_initialized || name == NULL || domain == NULL) { - if (!g_gen_json) LOG_FUNC_CALL_WARN("Cannot create histogram object"); + LOG_FUNC_CALL_WARN("Cannot create histogram object"); return NULL; } @@ -874,10 +837,10 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( if (h == NULL) { NEW_HISTOGRAM_A(&g_ref_collector_global, h, h_tail, domain, name, x_type, y_type); - if (!g_gen_json) LOG_FUNC_CALL_INFO("domain=%s, name=%s, x_type=%d, y_type=%d (created new histogram)", + LOG_FUNC_CALL_INFO("domain=%s, name=%s, x_type=%d, y_type=%d (created new histogram)", domain->nameA, name, x_type, y_type); } - else if (!g_gen_json) + else { LOG_FUNC_CALL_INFO("domain=%s, name=%s, x_type=%d, y_type=%d (histogram already exists)", domain->nameA, name, x_type, y_type); @@ -889,11 +852,7 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create( } // ---------------------------------------------------------------------------- -// Mode 2 event handlers (JSON) -// -// One json_* handler per traced ITT API call; every handler writes through -// json_write(). Argument validation lives inside each handler so the ITT entry -// points (further below) can stay as thin one-line dispatchers. +// JSON event handlers (mode 2) // ---------------------------------------------------------------------------- static void json_pause(void) @@ -930,8 +889,6 @@ static void json_detach(void) ",\"s\":\"t\",\"args\":{\"api\":\"detach\"}"); } -// Emit a Chrome/Perfetto "thread_name" metadata (M) event so the calling -// thread's track is labeled in the UI. static void json_thread_set_name(const char* name) { if (name == NULL) return; @@ -1036,7 +993,8 @@ static void json_metadata_add(const __itt_domain *domain, free(metadata_str); } -static void json_formatted_metadata_add(const __itt_domain *domain, const char* formatted_metadata) +static void json_formatted_metadata_add( + const __itt_domain *domain, const char* formatted_metadata) { if (domain == NULL) return; char data_esc[LOG_BUFFER_MAX_SIZE]; @@ -1046,7 +1004,8 @@ static void json_formatted_metadata_add(const __itt_domain *domain, const char* snprintf(extra, sizeof(extra), ",\"s\":\"t\",\"args\":{\"api\":\"metadata\",\"data\":\"%s\"}", data_esc); - json_write("i", domain->nameA, "__itt_formatted_metadata_add", get_timestamp_us(), extra); + json_write("i", domain->nameA, "__itt_formatted_metadata_add", + get_timestamp_us(), extra); } static void json_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) @@ -1084,7 +1043,8 @@ static void json_histogram_submit(__itt_histogram* hist, size_t length, void* x_ json_write("i", hist->domain->nameA, hist->nameA, get_timestamp_us(), extra); } -static void json_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +static void json_bind_context_metadata_to_counter( + __itt_counter counter, size_t length, __itt_context_metadata* metadata) { if (counter == NULL || metadata == NULL || length == 0) return; __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; @@ -1119,204 +1079,67 @@ static void json_counter_set_value_v3(__itt_counter counter, void* value_ptr) } // ---------------------------------------------------------------------------- -// Mode 1 event handlers (plain-text log) +// ITT API entry points (traced events) // -// One log_* handler per traced ITT API call, mirroring the json_* handlers -// above. Each writes a single human-readable line via the LOG_CALL_* macros -// (which take the explicit ITT API name). Argument validation lives here too. +// Each entry point writes the plain-text log line (mode 1) +// or delegates to the matching json_* handler (mode 2) instead. // ---------------------------------------------------------------------------- -static void log_pause(void) -{ - LOG_CALL_INFO("__itt_pause"); -} - -static void log_pause_scoped(__itt_collection_scope scope) -{ - LOG_CALL_INFO("__itt_pause_scoped", "scope=%d", scope); -} - -static void log_resume(void) -{ - LOG_CALL_INFO("__itt_resume"); -} - -static void log_resume_scoped(__itt_collection_scope scope) -{ - LOG_CALL_INFO("__itt_resume_scoped", "scope=%d", scope); -} - -static void log_detach(void) -{ - LOG_CALL_INFO("__itt_detach"); -} - -static void log_frame_begin_v3(const __itt_domain *domain, __itt_id *id) -{ - (void)id; - if (domain == NULL) { LOG_CALL_WARN("__itt_frame_begin_v3", "Incorrect function call"); return; } - LOG_CALL_INFO("__itt_frame_begin_v3", "domain=%s", domain->nameA); -} - -static void log_frame_end_v3(const __itt_domain *domain, __itt_id *id) -{ - (void)id; - if (domain == NULL) { LOG_CALL_WARN("__itt_frame_end_v3", "Incorrect function call"); return; } - LOG_CALL_INFO("__itt_frame_end_v3", "domain=%s", domain->nameA); -} - -static void log_frame_submit_v3(const __itt_domain *domain, __itt_timestamp begin, __itt_timestamp end) -{ - if (domain == NULL) { LOG_CALL_WARN("__itt_frame_submit_v3", "Incorrect function call"); return; } - LOG_CALL_INFO("__itt_frame_submit_v3", "domain=%s, time_begin=%llu, time_end=%llu", - domain->nameA, begin, end); -} - -static void log_task_begin(const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) -{ - if (domain == NULL || name == NULL) { LOG_CALL_WARN("__itt_task_begin", "Incorrect function call"); return; } - LOG_CALL_INFO("__itt_task_begin", "domain=%s name=%s taskid=%llu,%llu,%llu parentid=%llu,%llu,%llu", - domain->nameA, name->strA, - taskid.d1, taskid.d2, taskid.d3, - parentid.d1, parentid.d2, parentid.d3); -} - -static void log_task_end(const __itt_domain *domain) -{ - if (domain == NULL) { LOG_CALL_WARN("__itt_task_end", "Incorrect function call"); return; } - LOG_CALL_INFO("__itt_task_end", "domain=%s", domain->nameA); -} - -static void log_region_begin(const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) -{ - if (domain == NULL || name == NULL) { LOG_CALL_WARN("__itt_region_begin", "Incorrect function call"); return; } - LOG_CALL_INFO("__itt_region_begin", "domain=%s name=%s id=%llu,%llu,%llu parentid=%llu,%llu,%llu", - domain->nameA, name->strA, - id.d1, id.d2, id.d3, - parentid.d1, parentid.d2, parentid.d3); -} - -static void log_region_end(const __itt_domain *domain, __itt_id id) -{ - if (domain == NULL) { LOG_CALL_WARN("__itt_region_end", "Incorrect function call"); return; } - LOG_CALL_INFO("__itt_region_end", "domain=%s id=%llu,%llu,%llu", - domain->nameA, id.d1, id.d2, id.d3); -} - -static void log_metadata_add(const __itt_domain *domain, __itt_metadata_type type, size_t count, void *data) -{ - if (domain == NULL || count == 0) { LOG_CALL_WARN("__itt_metadata_add", "Incorrect function call"); return; } - char* metadata_str = get_metadata_elements(count, type, data); - LOG_CALL_INFO("__itt_metadata_add", "domain=%s metadata_size=%zu metadata[]=%s", - domain->nameA, count, metadata_str); - free(metadata_str); -} - -static void log_formatted_metadata_add(const __itt_domain *domain, const char* formatted_metadata) -{ - LOG_CALL_INFO("__itt_formatted_metadata_add", "domain=%s formatted_metadata=%s", - domain->nameA, formatted_metadata); -} - -static void log_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) +ITT_EXTERN_C void ITTAPI __itt_pause(void) { - if (hist == NULL) { LOG_CALL_WARN("__itt_histogram_submit", "Histogram is NULL"); return; } - if (hist->domain == NULL) { LOG_CALL_WARN("__itt_histogram_submit", "Histogram domain is NULL"); return; } - if (hist->domain->nameA == NULL || hist->nameA == NULL || length == 0 || y_data == NULL) + if (g_ref_collector_logger.gen_json) { - LOG_CALL_WARN("__itt_histogram_submit", "Incorrect function call"); + json_pause(); return; } - char* y_str = get_metadata_elements(length, hist->y_type, y_data); - if (x_data != NULL) - { - char* x_str = get_metadata_elements(length, hist->x_type, x_data); - LOG_CALL_INFO("__itt_histogram_submit", "histogram_name=%s length=%zu x_data[]=%s y_data[]=%s", - hist->nameA, length, x_str, y_str); - free(x_str); - } - else - { - LOG_CALL_INFO("__itt_histogram_submit", "histogram_name=%s length=%zu y_data[]=%s", - hist->nameA, length, y_str); - } - free(y_str); + LOG_FUNC_CALL_INFO(); } -static void log_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) { - if (counter == NULL || metadata == NULL || length == 0) + if (g_ref_collector_logger.gen_json) { - LOG_CALL_WARN("__itt_bind_context_metadata_to_counter", "Incorrect function call"); + json_pause_scoped(scope); return; } - __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; - char context_metadata[LOG_BUFFER_MAX_SIZE]; - build_context_metadata_str(context_metadata, sizeof(context_metadata), length, metadata); - LOG_CALL_INFO("__itt_bind_context_metadata_to_counter", - "counter_name=%s context_metadata_size=%zu context_metadata[]=%s", - (counter_info->nameA != NULL) ? counter_info->nameA : "", length, context_metadata); + LOG_FUNC_CALL_INFO("scope=%d", scope); } -static void log_counter_set_value_v3(__itt_counter counter, void* value_ptr) +ITT_EXTERN_C void ITTAPI __itt_resume(void) { - if (counter == NULL || value_ptr == NULL) + if (g_ref_collector_logger.gen_json) { - LOG_CALL_WARN("__itt_counter_set_value_v3", "Incorrect function call"); + json_resume(); return; } - __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; - uint64_t value = *(uint64_t*)value_ptr; - LOG_CALL_INFO("__itt_counter_set_value_v3", "counter_name=%s counter_value=%" PRIu64, - (counter_info->nameA != NULL) ? counter_info->nameA : "", value); -} - -// ---------------------------------------------------------------------------- -// ITT API entry points (traced events) -// -// Thin dispatchers: select the plain-text logger (mode 1) or the JSON writer -// (mode 2) based on g_gen_json. All validation and formatting lives in the -// matching log_* / json_* handlers above. -// ---------------------------------------------------------------------------- - -ITT_EXTERN_C void ITTAPI __itt_pause(void) -{ - if (!g_gen_json) log_pause(); - else json_pause(); -} - -ITT_EXTERN_C void ITTAPI __itt_pause_scoped(__itt_collection_scope scope) -{ - if (!g_gen_json) log_pause_scoped(scope); - else json_pause_scoped(scope); -} - -ITT_EXTERN_C void ITTAPI __itt_resume(void) -{ - if (!g_gen_json) log_resume(); - else json_resume(); + LOG_FUNC_CALL_INFO(); } ITT_EXTERN_C void ITTAPI __itt_resume_scoped(__itt_collection_scope scope) { - if (!g_gen_json) log_resume_scoped(scope); - else json_resume_scoped(scope); + if (g_ref_collector_logger.gen_json) + { + json_resume_scoped(scope); + return; + } + LOG_FUNC_CALL_INFO("scope=%d", scope); } ITT_EXTERN_C void ITTAPI __itt_detach(void) { - if (!g_gen_json) log_detach(); - else json_detach(); + if (g_ref_collector_logger.gen_json) + { + json_detach(); + return; + } + LOG_FUNC_CALL_INFO(); } -// __itt_thread_set_name has no plain-text log realization: the original -// reference collector never logged it. In JSON mode it labels the thread track. #ifdef _WIN32 ITT_EXTERN_C void ITTAPI __itt_thread_set_nameW(const wchar_t *name) { - if (!g_gen_json) return; char* name_a = wchar2char(name); - json_thread_set_name(name_a); + __itt_thread_set_nameA(name_a); free(name_a); } ITT_EXTERN_C void ITTAPI __itt_thread_set_nameA(const char *name) @@ -1324,70 +1147,162 @@ ITT_EXTERN_C void ITTAPI __itt_thread_set_nameA(const char *name) ITT_EXTERN_C void ITTAPI __itt_thread_set_name(const char *name) #endif { - if (g_gen_json) json_thread_set_name(name); + if (g_ref_collector_logger.gen_json) + { + json_thread_set_name(name); + return; + } + if (name == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("name=%s", name); } ITT_EXTERN_C void ITTAPI __itt_frame_begin_v3(const __itt_domain *domain, __itt_id *id) { - if (!g_gen_json) log_frame_begin_v3(domain, id); - else json_frame_begin_v3(domain, id); + if (g_ref_collector_logger.gen_json) + { + json_frame_begin_v3(domain, id); + return; + } + if (domain == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("domain=%s", domain->nameA); } ITT_EXTERN_C void ITTAPI __itt_frame_end_v3(const __itt_domain *domain, __itt_id *id) { - if (!g_gen_json) log_frame_end_v3(domain, id); - else json_frame_end_v3(domain, id); + if (g_ref_collector_logger.gen_json) + { + json_frame_end_v3(domain, id); + return; + } + if (domain == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("domain=%s", domain->nameA); } ITT_EXTERN_C void ITTAPI __itt_frame_submit_v3(const __itt_domain *domain, __itt_id *id, __itt_timestamp begin, __itt_timestamp end) { (void)id; - if (!g_gen_json) log_frame_submit_v3(domain, begin, end); - else json_frame_submit_v3(domain, begin, end); + if (g_ref_collector_logger.gen_json) + { + json_frame_submit_v3(domain, begin, end); + return; + } + if (domain == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("domain=%s, time_begin=%llu, time_end=%llu", + domain->nameA, begin, end); } ITT_EXTERN_C void ITTAPI __itt_task_begin( const __itt_domain *domain, __itt_id taskid, __itt_id parentid, __itt_string_handle *name) { - if (!g_gen_json) log_task_begin(domain, taskid, parentid, name); - else json_task_begin(domain, taskid, parentid, name); + if (g_ref_collector_logger.gen_json) + { + json_task_begin(domain, taskid, parentid, name); + return; + } + if (domain == NULL || name == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("domain=%s name=%s taskid=%llu,%llu,%llu parentid=%llu,%llu,%llu", + domain->nameA, name->strA, + taskid.d1, taskid.d2, taskid.d3, + parentid.d1, parentid.d2, parentid.d3); } ITT_EXTERN_C void ITTAPI __itt_task_end(const __itt_domain *domain) { - if (!g_gen_json) log_task_end(domain); - else json_task_end(domain); + if (g_ref_collector_logger.gen_json) + { + json_task_end(domain); + return; + } + if (domain == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("domain=%s", domain->nameA); } ITT_EXTERN_C void ITTAPI __itt_region_begin( const __itt_domain *domain, __itt_id id, __itt_id parentid, __itt_string_handle *name) { - if (!g_gen_json) log_region_begin(domain, id, parentid, name); - else json_region_begin(domain, id, name); + if (g_ref_collector_logger.gen_json) + { + json_region_begin(domain, id, name); + return; + } + if (domain == NULL || name == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("domain=%s name=%s id=%llu,%llu,%llu parentid=%llu,%llu,%llu", + domain->nameA, name->strA, + id.d1, id.d2, id.d3, + parentid.d1, parentid.d2, parentid.d3); } ITT_EXTERN_C void ITTAPI __itt_region_end(const __itt_domain *domain, __itt_id id) { - if (!g_gen_json) log_region_end(domain, id); - else json_region_end(domain, id); + if (g_ref_collector_logger.gen_json) + { + json_region_end(domain, id); + return; + } + if (domain == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + LOG_FUNC_CALL_INFO("domain=%s id=%llu,%llu,%llu", + domain->nameA, id.d1, id.d2, id.d3); } ITT_EXTERN_C void __itt_metadata_add(const __itt_domain *domain, __itt_id id, __itt_string_handle *key, __itt_metadata_type type, size_t count, void *data) { (void)id; - if (!g_gen_json) log_metadata_add(domain, type, count, data); - else json_metadata_add(domain, key, type, count, data); + if (g_ref_collector_logger.gen_json) + { + json_metadata_add(domain, key, type, count, data); + return; + } + if (domain == NULL || count == 0) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + char* metadata_str = get_metadata_elements(count, type, data); + LOG_FUNC_CALL_INFO("domain=%s metadata_size=%zu metadata[]=%s", + domain->nameA, count, (metadata_str != NULL) ? metadata_str : ""); + free(metadata_str); } -ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt_string_handle *format, ...) +ITT_EXTERN_C void __itt_formatted_metadata_add( + const __itt_domain *domain, __itt_string_handle *format, ...) { - // Formatting the variadic args must happen here (in the entry point) before - // dispatching, so validate up front too. if (domain == NULL || format == NULL) { - if (!g_gen_json) LOG_CALL_WARN("__itt_formatted_metadata_add", "Incorrect function call"); + LOG_FUNC_CALL_WARN("Incorrect function call"); return; } @@ -1397,24 +1312,88 @@ ITT_EXTERN_C void __itt_formatted_metadata_add(const __itt_domain *domain, __itt vsnprintf(formatted_metadata, LOG_BUFFER_MAX_SIZE, format->strA, args); va_end(args); - if (!g_gen_json) log_formatted_metadata_add(domain, formatted_metadata); - else json_formatted_metadata_add(domain, formatted_metadata); + if (g_ref_collector_logger.gen_json) + { + json_formatted_metadata_add(domain, formatted_metadata); + return; + } + LOG_FUNC_CALL_INFO("domain=%s formatted_metadata=%s", domain->nameA, formatted_metadata); } -ITT_EXTERN_C void __itt_histogram_submit(__itt_histogram* hist, size_t length, void* x_data, void* y_data) +ITT_EXTERN_C void __itt_histogram_submit( + __itt_histogram* hist, size_t length, void* x_data, void* y_data) { - if (!g_gen_json) log_histogram_submit(hist, length, x_data, y_data); - else json_histogram_submit(hist, length, x_data, y_data); + if (g_ref_collector_logger.gen_json) + { + json_histogram_submit(hist, length, x_data, y_data); + return; + } + if (hist == NULL) + { + LOG_FUNC_CALL_WARN("Histogram is NULL"); + return; + } + if (hist->domain == NULL) + { + LOG_FUNC_CALL_WARN("Histogram domain is NULL"); + return; + } + if (hist->domain->nameA == NULL || hist->nameA == NULL || length == 0 || y_data == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + char* y_str = get_metadata_elements(length, hist->y_type, y_data); + if (x_data != NULL) + { + char* x_str = get_metadata_elements(length, hist->x_type, x_data); + LOG_FUNC_CALL_INFO("histogram_name=%s length=%zu x_data[]=%s y_data[]=%s", + hist->nameA, length, + (x_str != NULL) ? x_str : "", (y_str != NULL) ? y_str : ""); + free(x_str); + } + else + { + LOG_FUNC_CALL_INFO("histogram_name=%s length=%zu y_data[]=%s", + hist->nameA, length, (y_str != NULL) ? y_str : ""); + } + free(y_str); } -ITT_EXTERN_C void __itt_bind_context_metadata_to_counter(__itt_counter counter, size_t length, __itt_context_metadata* metadata) +ITT_EXTERN_C void __itt_bind_context_metadata_to_counter( + __itt_counter counter, size_t length, __itt_context_metadata* metadata) { - if (!g_gen_json) log_bind_context_metadata_to_counter(counter, length, metadata); - else json_bind_context_metadata_to_counter(counter, length, metadata); + if (g_ref_collector_logger.gen_json) + { + json_bind_context_metadata_to_counter(counter, length, metadata); + return; + } + if (counter == NULL || metadata == NULL || length == 0) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + char context_metadata[LOG_BUFFER_MAX_SIZE]; + build_context_metadata_str(context_metadata, sizeof(context_metadata), length, metadata); + LOG_FUNC_CALL_INFO("counter_name=%s context_metadata_size=%zu context_metadata[]=%s", + (counter_info->nameA != NULL) ? counter_info->nameA : "", length, context_metadata); } ITT_EXTERN_C void __itt_counter_set_value_v3(__itt_counter counter, void* value_ptr) { - if (!g_gen_json) log_counter_set_value_v3(counter, value_ptr); - else json_counter_set_value_v3(counter, value_ptr); + if (g_ref_collector_logger.gen_json) + { + json_counter_set_value_v3(counter, value_ptr); + return; + } + if (counter == NULL || value_ptr == NULL) + { + LOG_FUNC_CALL_WARN("Incorrect function call"); + return; + } + __itt_counter_info_t* counter_info = (__itt_counter_info_t*)counter; + uint64_t value = *(uint64_t*)value_ptr; + LOG_FUNC_CALL_INFO("counter_name=%s counter_value=%" PRIu64, + (counter_info->nameA != NULL) ? counter_info->nameA : "", value); } From 076ca2bcb31a6bcdbc694b52f5c0635c2f597c5e Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Fri, 17 Jul 2026 10:32:02 -0500 Subject: [PATCH 07/10] fix minor issues --- src/ittnotify_refcol/CMakeLists.txt | 6 +++ src/ittnotify_refcol/README.md | 13 +---- src/ittnotify_refcol/itt_refcol_impl.c | 72 +++++++++++++++++--------- 3 files changed, 54 insertions(+), 37 deletions(-) diff --git a/src/ittnotify_refcol/CMakeLists.txt b/src/ittnotify_refcol/CMakeLists.txt index e05d2975..a1da60c9 100644 --- a/src/ittnotify_refcol/CMakeLists.txt +++ b/src/ittnotify_refcol/CMakeLists.txt @@ -37,6 +37,12 @@ target_include_directories(ittnotify_refcol PRIVATE target_link_libraries(ittnotify_refcol PRIVATE ${CMAKE_DL_LIBS}) +if(MSVC) + target_compile_options(ittnotify_refcol PRIVATE /W4) +else() + target_compile_options(ittnotify_refcol PRIVATE -Wall -Wextra) +endif() + if(WIN32) target_compile_definitions(ittnotify_refcol PRIVATE _CRT_SECURE_NO_WARNINGS) set_target_properties(ittnotify_refcol PROPERTIES diff --git a/src/ittnotify_refcol/README.md b/src/ittnotify_refcol/README.md index da39b195..0c18882b 100644 --- a/src/ittnotify_refcol/README.md +++ b/src/ittnotify_refcol/README.md @@ -42,12 +42,6 @@ library you built above (adjust the path to your build directory). export INTEL_LIBITTNOTIFY64=/libittnotify_refcol.so ``` -**On FreeBSD** - -``` -setenv INTEL_LIBITTNOTIFY64 /libittnotify_refcol.so -``` - **On Windows** ``` @@ -63,11 +57,6 @@ the location, use the `INTEL_LIBITTNOTIFY_LOG_DIR` environment variable: export INTEL_LIBITTNOTIFY_LOG_DIR= ``` -**On FreeBSD** -``` -setenv INTEL_LIBITTNOTIFY_LOG_DIR -``` - **On Windows** ``` set INTEL_LIBITTNOTIFY_LOG_DIR= @@ -92,7 +81,7 @@ This mode is experimental and is disabled by default. To enable it, set the `EXP_LIBITTNOTIFY_GEN_JSON` environment variable to `1`: -**On Linux / FreeBSD** +**On Linux** ``` export EXP_LIBITTNOTIFY_GEN_JSON=1 diff --git a/src/ittnotify_refcol/itt_refcol_impl.c b/src/ittnotify_refcol/itt_refcol_impl.c index 1e7b8e90..9e6b9b63 100644 --- a/src/ittnotify_refcol/itt_refcol_impl.c +++ b/src/ittnotify_refcol/itt_refcol_impl.c @@ -24,9 +24,9 @@ #define LOG_BUFFER_MAX_SIZE 256 -static const char* env_log_dir = "INTEL_LIBITTNOTIFY_LOG_DIR"; -static const char* log_level_str[] = {"INFO", "WARN", "ERROR", "FATAL_ERROR"}; +static const char* env_log_dir = "INTEL_LIBITTNOTIFY_LOG_DIR"; static const char* env_gen_json = "EXP_LIBITTNOTIFY_GEN_JSON"; +static const char* log_level_str[] = {"INFO", "WARN", "ERROR", "FATAL_ERROR"}; enum { LOG_LVL_INFO, @@ -538,12 +538,13 @@ static char* wchar2char(const wchar_t* wide_str) #endif // Write one line per instrumented ITT API call to a .log file. -// No-op in JSON mode, so callers can log unconditionally. static void log_func_call( uint8_t log_level, const char* function_name, const char* message_format, ...) { if (g_ref_collector_logger.gen_json) + { return; + } if (!g_ref_collector_logger.init_state || !g_ref_collector_logger.log_fp) { @@ -564,7 +565,16 @@ static void log_func_call( message_format, message_args); va_end(message_args); - fprintf(g_ref_collector_logger.log_fp, "%s\n", log_buffer); + if (g_ref_collector_global.mutex_initialized) + { + __itt_mutex_lock(&g_ref_collector_global.mutex); + fprintf(g_ref_collector_logger.log_fp, "%s\n", log_buffer); + __itt_mutex_unlock(&g_ref_collector_global.mutex); + } + else + { + printf("ERROR: Failed to log function call\n"); + } } static void log_api_call( @@ -641,6 +651,7 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) } __itt_domain *h_tail = NULL, *h = NULL; + int created = 0; __itt_mutex_lock(&g_ref_collector_global.mutex); @@ -652,15 +663,16 @@ ITT_EXTERN_C __itt_domain* ITTAPI __itt_domain_create(const char *name) if (h == NULL) { NEW_DOMAIN_A(&g_ref_collector_global, h, h_tail, name); - LOG_FUNC_CALL_INFO("name=%s (created new domain)", name); - } - else - { - LOG_FUNC_CALL_INFO("name=%s (domain already exists)", name); + created = 1; } __itt_mutex_unlock(&g_ref_collector_global.mutex); + if (created) + LOG_FUNC_CALL_INFO("name=%s (created new domain)", name); + else + LOG_FUNC_CALL_INFO("name=%s (domain already exists)", name); + return h; } @@ -684,6 +696,7 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* } __itt_string_handle *h_tail = NULL, *h = NULL; + int created = 0; __itt_mutex_lock(&g_ref_collector_global.mutex); @@ -695,15 +708,16 @@ ITT_EXTERN_C __itt_string_handle* ITTAPI __itt_string_handle_create(const char* if (h == NULL) { NEW_STRING_HANDLE_A(&g_ref_collector_global, h, h_tail, name); - LOG_FUNC_CALL_INFO("name=%s (created new string handle)", name); - } - else - { - LOG_FUNC_CALL_INFO("name=%s (string handle already exists)", name); + created = 1; } __itt_mutex_unlock(&g_ref_collector_global.mutex); + if (created) + LOG_FUNC_CALL_INFO("name=%s (created new string handle)", name); + else + LOG_FUNC_CALL_INFO("name=%s (string handle already exists)", name); + return h; } @@ -729,7 +743,11 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create(const char *name, const c ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_createW_v3( const __itt_domain* domain, const wchar_t* name, __itt_metadata_type type) { - if (domain == NULL) return NULL; + if (domain == NULL) + { + LOG_FUNC_CALL_WARN("domain is NULL"); + return NULL; + } char* name_a = wchar2char(name); if (name_a == NULL) return NULL; __itt_counter result = __itt_counter_create_typed(name_a, domain->nameA, type); @@ -776,6 +794,7 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( } __itt_counter_info_t *h_tail = NULL, *h = NULL; + int created = 0; __itt_mutex_lock(&g_ref_collector_global.mutex); @@ -789,16 +808,17 @@ ITT_EXTERN_C __itt_counter ITTAPI __itt_counter_create_typed( if (h == NULL) { NEW_COUNTER_A(&g_ref_collector_global, h, h_tail, name, domain, type); + created = 1; + } + + __itt_mutex_unlock(&g_ref_collector_global.mutex); + + if (created) LOG_FUNC_CALL_INFO("name=%s, domain=%s, type=%d (created new counter)", name, domain, (int)type); - } else - { LOG_FUNC_CALL_INFO("name=%s, domain=%s, type=%d (counter already exists)", name, domain, (int)type); - } - - __itt_mutex_unlock(&g_ref_collector_global.mutex); return (__itt_counter)h; } @@ -826,6 +846,7 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create(const __itt_domain* } __itt_histogram *h_tail = NULL, *h = NULL; + int created = 0; __itt_mutex_lock(&g_ref_collector_global.mutex); @@ -837,16 +858,17 @@ ITT_EXTERN_C __itt_histogram* ITTAPI __itt_histogram_create(const __itt_domain* if (h == NULL) { NEW_HISTOGRAM_A(&g_ref_collector_global, h, h_tail, domain, name, x_type, y_type); + created = 1; + } + + __itt_mutex_unlock(&g_ref_collector_global.mutex); + + if (created) LOG_FUNC_CALL_INFO("domain=%s, name=%s, x_type=%d, y_type=%d (created new histogram)", domain->nameA, name, x_type, y_type); - } else - { LOG_FUNC_CALL_INFO("domain=%s, name=%s, x_type=%d, y_type=%d (histogram already exists)", domain->nameA, name, x_type, y_type); - } - - __itt_mutex_unlock(&g_ref_collector_global.mutex); return h; } From 1d8c6cbf9dd83bee15b5049f90bb4f67a5a31274 Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Fri, 17 Jul 2026 12:35:04 -0500 Subject: [PATCH 08/10] change default log dir to cwd --- src/ittnotify_refcol/README.md | 6 +++--- src/ittnotify_refcol/itt_refcol_impl.c | 14 +------------- 2 files changed, 4 insertions(+), 16 deletions(-) diff --git a/src/ittnotify_refcol/README.md b/src/ittnotify_refcol/README.md index 0c18882b..0cac2b4a 100644 --- a/src/ittnotify_refcol/README.md +++ b/src/ittnotify_refcol/README.md @@ -48,7 +48,7 @@ export INTEL_LIBITTNOTIFY64=/libittnotify_refcol.so set INTEL_LIBITTNOTIFY64=\libittnotify_refcol.dll ``` -By default, log files are saved in the system temporary directory. To change +By default, log files are saved in the current working directory. To change the location, use the `INTEL_LIBITTNOTIFY_LOG_DIR` environment variable: **On Linux** @@ -75,8 +75,8 @@ LOG_FUNC_CALL_FATAL(const char *msg_format, ...); ## Experimental: JSON trace generation -In addition to the default text log, the collector can produce a -[Perfetto / Chrome Trace Event](https://ui.perfetto.dev) trace in JSON format. +In addition to the default text log, the collector can produce a trace in +JSON format (Perfetto). This mode is experimental and is disabled by default. To enable it, set the `EXP_LIBITTNOTIFY_GEN_JSON` environment variable to `1`: diff --git a/src/ittnotify_refcol/itt_refcol_impl.c b/src/ittnotify_refcol/itt_refcol_impl.c index 9e6b9b63..b216ba81 100644 --- a/src/ittnotify_refcol/itt_refcol_impl.c +++ b/src/ittnotify_refcol/itt_refcol_impl.c @@ -116,19 +116,7 @@ static void ref_collector_init(void) } else { - #ifdef _WIN32 - char* temp_dir = getenv("TEMP"); - if (temp_dir != NULL) - { - snprintf(file_name_buffer, sizeof(file_name_buffer), "%s\\%s", temp_dir, log_file); - } - else - { - snprintf(file_name_buffer, sizeof(file_name_buffer), "%s", log_file); - } - #else - snprintf(file_name_buffer, sizeof(file_name_buffer), "/tmp/%s", log_file); - #endif + snprintf(file_name_buffer, sizeof(file_name_buffer), "%s", log_file); } free(log_file); From 6d903bdfe01f29ee9e5ae28921cb756b7bdadddb Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Fri, 17 Jul 2026 12:36:44 -0500 Subject: [PATCH 09/10] detele -wall compilation flag --- src/ittnotify_refcol/CMakeLists.txt | 6 ------ 1 file changed, 6 deletions(-) diff --git a/src/ittnotify_refcol/CMakeLists.txt b/src/ittnotify_refcol/CMakeLists.txt index a1da60c9..e05d2975 100644 --- a/src/ittnotify_refcol/CMakeLists.txt +++ b/src/ittnotify_refcol/CMakeLists.txt @@ -37,12 +37,6 @@ target_include_directories(ittnotify_refcol PRIVATE target_link_libraries(ittnotify_refcol PRIVATE ${CMAKE_DL_LIBS}) -if(MSVC) - target_compile_options(ittnotify_refcol PRIVATE /W4) -else() - target_compile_options(ittnotify_refcol PRIVATE -Wall -Wextra) -endif() - if(WIN32) target_compile_definitions(ittnotify_refcol PRIVATE _CRT_SECURE_NO_WARNINGS) set_target_properties(ittnotify_refcol PROPERTIES From c7d1c62cbd16e4e18f097642a6f3b072b29af5df Mon Sep 17 00:00:00 2001 From: "Parshutin, Eugeny" Date: Fri, 17 Jul 2026 12:41:42 -0500 Subject: [PATCH 10/10] update docs --- docs/src/ref_collector.rst | 47 ++++++++++++++++++++++------------ src/ittnotify_refcol/README.md | 2 +- 2 files changed, 31 insertions(+), 18 deletions(-) diff --git a/docs/src/ref_collector.rst b/docs/src/ref_collector.rst index ae64e60d..4a3db740 100644 --- a/docs/src/ref_collector.rst +++ b/docs/src/ref_collector.rst @@ -59,14 +59,6 @@ library you built above (adjust the path to your build directory). export INTEL_LIBITTNOTIFY64=/libittnotify_refcol.so -**On FreeBSD** - - -.. code-block:: bash - - setenv INTEL_LIBITTNOTIFY64 /libittnotify_refcol.so - - **On Windows** @@ -78,7 +70,7 @@ library you built above (adjust the path to your build directory). Log File Location ----------------- -By default, log files are saved in the system temporary directory. Each run +By default, log files are saved in the current working directory. Each run creates a file named ``libittnotify_refcol_.log``. To change the location, use the ``INTEL_LIBITTNOTIFY_LOG_DIR`` environment variable: @@ -91,14 +83,6 @@ location, use the ``INTEL_LIBITTNOTIFY_LOG_DIR`` environment variable: export INTEL_LIBITTNOTIFY_LOG_DIR= -**On FreeBSD** - - -.. code-block:: bash - - setenv INTEL_LIBITTNOTIFY_LOG_DIR - - **On Windows** @@ -121,3 +105,32 @@ functions with different log levels that take `printf` format for logging: LOG_FUNC_CALL_ERROR(const char *msg_format, ...); LOG_FUNC_CALL_FATAL(const char *msg_format, ...); + +Experimental: JSON trace generation +------------------------------------ + +In addition to the default text log, the collector can produce a trace in +JSON format (Perfetto). This mode is experimental and is disabled by default. + +To enable it, set the ``EXP_LIBITTNOTIFY_GEN_JSON`` environment variable to ``1``: + +**On Linux** + + +.. code-block:: bash + + export EXP_LIBITTNOTIFY_GEN_JSON=1 + + +**On Windows** + + +.. code-block:: bat + + set EXP_LIBITTNOTIFY_GEN_JSON=1 + + +When enabled, the collector writes a ``libittnotify_refcol_.json`` +file (instead of the text log) into the log directory. The file can be opened +directly in https://ui.perfetto.dev. + diff --git a/src/ittnotify_refcol/README.md b/src/ittnotify_refcol/README.md index 0cac2b4a..0ca7949f 100644 --- a/src/ittnotify_refcol/README.md +++ b/src/ittnotify_refcol/README.md @@ -95,4 +95,4 @@ set EXP_LIBITTNOTIFY_GEN_JSON=1 When enabled, the collector writes a `libittnotify_refcol_.json` file (instead of the text log) into the log directory. The file can be opened -directly in or `chrome://tracing`. +directly in .