Skip to content

[SYCL][XPTI] Add support for tracing Level Zero API calls #6023

New issue

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

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

Already on GitHub? Sign in to your account

Merged
merged 14 commits into from
Apr 25, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
20 changes: 20 additions & 0 deletions sycl/doc/design/SYCLInstrumentationUsingXPTI.md
Original file line number Diff line number Diff line change
Expand Up @@ -300,3 +300,23 @@ All trace point types in bold provide semantic information about the graph, node
| `mem_alloc_end` | <div style="text-align: left"><li>**trace_type**: `xpti::trace_point_type_t::mem_alloc_end` that marks the end of memory allocation process</li> <li> **parent**: Event ID created for all functions in the `oneapi.level_zero.experimental.mem_alloc` layer.</li> <li> **event**: `nullptr` - since the stream of data just captures functions being called.</li> <li> **instance**: Unique ID to allow the correlation of the `mem_alloc_begin` event with the `mem_alloc_end` event. This value is guaranteed to be the same value received by the trace event for the corresponding `mem_alloc_begin`.</li> <li> **user_data**: A pointer to `mem_alloc_data_t` object, that includes memory object ID (if any), allocated pointer, allocation size, and guard zone size (if any). </li></div> | None |
| `mem_release_begin` | <div style="text-align: left"><li>**trace_type**: `xpti::trace_point_type_t::mem_release_begin` that marks the beginning of memory allocation process</li> <li> **parent**: Event ID created for all functions in the `oneapi.level_zero.experimental.mem_alloc` layer.</li> <li> **event**: `nullptr` - since the stream of data just captures functions being called.</li> <li> **instance**: Unique ID to allow the correlation of the `mem_release_begin` event with the `mem_release_end` event. </li> <li> **user_data**: A pointer to `mem_alloc_data_t` object, that includes memory object ID (if any) and released pointer. </li></div> | None |
| `mem_release_end` | <div style="text-align: left"><li>**trace_type**: `xpti::trace_point_type_t::mem_release_end` that marks the end of memory allocation process</li> <li> **parent**: Event ID created for all functions in the `oneapi.level_zero.experimental.mem_alloc` layer.</li> <li> **event**: `nullptr` - since the stream of data just captures functions being called.</li> <li> **instance**: Unique ID to allow the correlation of the `mem_release_begin` event with the `mem_release_end` event. This value is guaranteed to be the same value received by the trace event for the corresponding `mem_release_begin`.</li> <li> **user_data**: A pointer to `mem_alloc_data_t` object, that includes memory object ID (if any) and released pointer. </li></div> | None |

## SYCL Stream `"sycl.experimental.level_zero.call"` Notification Signatures

This stream transfers events about Level Zero API calls made by SYCL
application.

| Trace Point Type | Parameter Description | Metadata |
| :--------------: | :-------------------- | :------- |
| `function_begin` | <div style="text-align: left"><li>**trace_type**: `xpti::trace_point_type_t::function_begin` that marks the beginning of a function</li> <li> **parent**: Event ID created for all functions in the `sycl.pi` layer.</li> <li> **event**: `nullptr` - since the stream of data just captures functions being called.</li> <li> **instance**: Unique ID to allow the correlation of the `function_begin` event with the `function_end` event. </li> <li> **user_data**: Name of the function being called sent in as `const char *` </li></div> | None |
| `function_end` | <div style="text-align: left"><li>**trace_type**: `xpti::trace_point_type_t::function_end` that marks the beginning of a function</li> <li> **parent**: Event ID created for all functions in the `sycl.pi` layer.</li> <li> **event**: `nullptr` - since the stream of data just captures functions being called.</li> <li> **instance**: Unique ID to allow the correlation of the `function_begin` event with the `function_end` event. This value is guaranteed to be the same value received by the trace event for the corresponding `function_begin` </li> <li> **user_data**: Name of the function being called sent in as `const char *` </li></div> | None |

## SYCL Stream `"sycl.experimental.level_zero.debug"` Notification Signatures

This stream transfers events about Level Zero API calls and their function
arguments made by SYCL application.

| Trace Point Type | Parameter Description | Metadata |
| :------------------------: | :-------------------- | :------- |
| `function_with_args_begin` | <div style="text-align: left"><li>**trace_type**: `xpti::trace_point_type_t::function_with_args_begin` that marks the beginning of a function</li> <li> **parent**: Event ID created for all functions in the `sycl.pi.debug` layer.</li> <li> **event**: `nullptr` - since the stream of data just captures functions being called.</li> <li> **instance**: Unique ID to allow the correlation of the `function_with_args_begin` event with the `function_with_args_end` event. </li> <li> **user_data**: A pointer to `function_with_args_t` object, that includes function ID, name, and arguments. </li></div> | None |
| `function_with_args_end` | <div style="text-align: left"><li>**trace_type**: `xpti::trace_point_type_t::function_with_args_end` that marks the beginning of a function</li> <li> **parent**: Event ID created for all functions in the `sycl.pi.debug` layer.</li> <li> **event**: `nullptr` - since the stream of data just captures functions being called.</li> <li> **instance**: Unique ID to allow the correlation of the `function_with_args_begin` event with the `function_with_args_end` event. This value is guaranteed to be the same value received by the trace event for the corresponding `function_with_args_begin` </li> <li> **user_data**: A pointer to `function_with_args_t` object, that includes function ID, name, arguments, and return value. </li></div> | None |
30 changes: 28 additions & 2 deletions sycl/plugins/level_zero/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -99,20 +99,46 @@ target_include_directories(LevelZeroLoader-Headers
INTERFACE "${LEVEL_ZERO_INCLUDE_DIR}"
)

find_package(Threads REQUIRED)
if (SYCL_ENABLE_XPTI_TRACING)
set(XPTI_PROXY_SRC "${CMAKE_SOURCE_DIR}/../xpti/src/xpti_proxy.cpp")
endif()

add_sycl_plugin(level_zero
SOURCES
"${sycl_inc_dir}/CL/sycl/detail/pi.h"
"${CMAKE_CURRENT_SOURCE_DIR}/pi_level_zero.cpp"
"${CMAKE_CURRENT_SOURCE_DIR}/pi_level_zero.hpp"
"${CMAKE_CURRENT_SOURCE_DIR}/usm_allocator.cpp"
"${CMAKE_CURRENT_SOURCE_DIR}/usm_allocator.hpp"
"${CMAKE_CURRENT_SOURCE_DIR}/tracing.cpp"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should include tracing.cpp into pi_level_zero.so only if (SYCL_ENABLE_XPTI_TRACING) is true.
Otherwise even release version of the library distributed to customers will contain unnecessary code which is used for debugging.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually I think we should do the opposite, i.e. remove the SYCL_ENABLE_XPTI_TRACING and always include the tracing capabilities. The "sycl-prof" and "sycl-trace" tools are meant to be available to the end-user, and should always produce the traces. FWIW, I already removed the SYCL_PI_LEVEL_ZERO_ENABLE_TRACING (made it to "1" always). Do you agree?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see. Yes, I agree.

${XPTI_PROXY_SRC}
LIBRARIES
"${LEVEL_ZERO_LOADER}"
Threads::Threads
)

find_package(Python3 REQUIRED)

add_custom_target(ze-api
COMMAND ${Python3_EXECUTABLE}
${CMAKE_CURRENT_SOURCE_DIR}/ze_api_generator.py
${LEVEL_ZERO_INCLUDE_DIR}/level_zero/ze_api.h
BYPRODUCTS
${CMAKE_CURRENT_BINARY_DIR}/ze_api.def
)
target_include_directories(pi_level_zero PRIVATE ${CMAKE_CURRENT_BINARY_DIR})
add_dependencies(pi_level_zero ze-api)

if (SYCL_ENABLE_XPTI_TRACING)
target_compile_definitions(pi_level_zero PRIVATE
XPTI_ENABLE_INSTRUMENTATION
XPTI_STATIC_LIBRARY
)
target_include_directories(pi_level_zero PRIVATE "${CMAKE_SOURCE_DIR}/../xpti/include")
target_link_libraries(pi_level_zero PRIVATE ${CMAKE_DL_LIBS})
endif()

Comment on lines +120 to +140
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should put this under if (SYCL_ENABLE_XPTI_TRACING) too.

if (TARGET level-zero-loader)
add_dependencies(ze-api level-zero-loader)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should put this under if (SYCL_ENABLE_XPTI_TRACING) too.

add_dependencies(pi_level_zero level-zero-loader)
endif()

7 changes: 7 additions & 0 deletions sycl/plugins/level_zero/pi_level_zero.cpp
100644 → 100755
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,10 @@ static pi_result EventCreate(pi_context Context, pi_queue Queue,
bool HostVisible, pi_event *RetEvent);
}

// Defined in tracing.cpp
void enableZeTracing();
void disableZeTracing();

namespace {

// Controls Level Zero calls serialization to w/a Level Zero driver being not MT
Expand Down Expand Up @@ -7942,6 +7946,7 @@ pi_result piPluginInit(pi_plugin *PluginInit) {
(PluginInit->PiFunctionTable).api = (decltype(&::api))(&api);
#include <CL/sycl/detail/pi.def>

enableZeTracing();
return PI_SUCCESS;
}

Expand Down Expand Up @@ -8048,6 +8053,8 @@ pi_result piTearDown(void *PluginParameter) {
}
if (LeakFound)
return PI_INVALID_MEM_OBJECT;

disableZeTracing();
return PI_SUCCESS;
}

Expand Down
151 changes: 151 additions & 0 deletions sycl/plugins/level_zero/tracing.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,151 @@
//===-------------- tracing.cpp - Level-Zero Host API Tracing --------------==//
//
// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
// See https://llvm.org/LICENSE.txt for license information.
// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
//
//===----------------------------------------------------------------------===//

#include "xpti/xpti_data_types.h"
#include <exception>
#include <level_zero/layers/zel_tracing_api.h>
#include <level_zero/ze_api.h>
#include <xpti/xpti_trace_framework.h>

#include <iostream>

constexpr auto ZE_CALL_STREAM_NAME = "sycl.experimental.level_zero.call";
constexpr auto ZE_DEBUG_STREAM_NAME = "sycl.experimental.level_zero.debug";

thread_local uint64_t CallCorrelationID = 0;
thread_local uint64_t DebugCorrelationID = 0;

constexpr auto GVerStr = "0.1";
constexpr int GMajVer = 0;
constexpr int GMinVer = 1;

#ifdef XPTI_ENABLE_INSTRUMENTATION
static xpti_td *GCallEvent = nullptr;
static xpti_td *GDebugEvent = nullptr;
#endif // XPTI_ENABLE_INSTRUMENTATION

enum class ZEApiKind {
#define _ZE_API(call, domain, cb, params_type) call,
#include "ze_api.def"
#undef _ZE_API
};

void enableZeTracing() {
#ifdef XPTI_ENABLE_INSTRUMENTATION
if (!xptiTraceEnabled())
return;

xptiRegisterStream(ZE_CALL_STREAM_NAME);
xptiInitialize(ZE_CALL_STREAM_NAME, GMajVer, GMinVer, GVerStr);
xptiRegisterStream(ZE_DEBUG_STREAM_NAME);
xptiInitialize(ZE_DEBUG_STREAM_NAME, GMajVer, GMinVer, GVerStr);

uint64_t Dummy;
xpti::payload_t ZePayload("Level Zero Plugin Layer");
GCallEvent =
xptiMakeEvent("Level Zero Plugin Layer", &ZePayload,
xpti::trace_algorithm_event, xpti_at::active, &Dummy);

xpti::payload_t ZeDebugPayload("Level Zero Plugin Debug Layer");
GDebugEvent =
xptiMakeEvent("Level Zero Plugin Debug Layer", &ZeDebugPayload,
xpti::trace_algorithm_event, xpti_at::active, &Dummy);

ze_result_t Status = zeInit(0);
if (Status != ZE_RESULT_SUCCESS) {
// Most likey there are no Level Zero devices.
return;
}

int Foo = 0;
zel_tracer_desc_t TracerDesc = {ZEL_STRUCTURE_TYPE_TRACER_EXP_DESC, nullptr,
&Foo};
zel_tracer_handle_t Tracer = nullptr;

Status = zelTracerCreate(&TracerDesc, &Tracer);

if (Status != ZE_RESULT_SUCCESS || Tracer == nullptr) {
std::cerr << "[WARNING] Failed to create Level Zero tracer: " << Status
<< "\n";
return;
}

zel_core_callbacks_t Prologue = {};
zel_core_callbacks_t Epilogue = {};

#define _ZE_API(call, domain, cb, params_type) \
Prologue.domain.cb = [](params_type *Params, ze_result_t, void *, void **) { \
if (xptiTraceEnabled()) { \
uint8_t CallStreamID = xptiRegisterStream(ZE_CALL_STREAM_NAME); \
uint8_t DebugStreamID = xptiRegisterStream(ZE_DEBUG_STREAM_NAME); \
CallCorrelationID = xptiGetUniqueId(); \
DebugCorrelationID = xptiGetUniqueId(); \
const char *FuncName = #call; \
xptiNotifySubscribers( \
CallStreamID, (uint16_t)xpti::trace_point_type_t::function_begin, \
GCallEvent, nullptr, CallCorrelationID, FuncName); \
uint32_t FuncID = static_cast<uint32_t>(ZEApiKind::call); \
xpti::function_with_args_t Payload{FuncID, FuncName, Params, nullptr, \
nullptr}; \
xptiNotifySubscribers( \
DebugStreamID, \
(uint16_t)xpti::trace_point_type_t::function_with_args_begin, \
GDebugEvent, nullptr, DebugCorrelationID, &Payload); \
} \
}; \
Epilogue.domain.cb = [](params_type *Params, ze_result_t Result, void *, \
void **) { \
if (xptiTraceEnabled()) { \
uint8_t CallStreamID = xptiRegisterStream(ZE_CALL_STREAM_NAME); \
uint8_t DebugStreamID = xptiRegisterStream(ZE_DEBUG_STREAM_NAME); \
const char *FuncName = #call; \
xptiNotifySubscribers(CallStreamID, \
(uint16_t)xpti::trace_point_type_t::function_end, \
GCallEvent, nullptr, CallCorrelationID, FuncName); \
uint32_t FuncID = static_cast<uint32_t>(ZEApiKind::call); \
xpti::function_with_args_t Payload{FuncID, FuncName, Params, &Result, \
nullptr}; \
xptiNotifySubscribers( \
DebugStreamID, \
(uint16_t)xpti::trace_point_type_t::function_with_args_end, \
GDebugEvent, nullptr, DebugCorrelationID, &Payload); \
} \
};

#include "ze_api.def"

#undef _ZE_API

Status = zelTracerSetPrologues(Tracer, &Prologue);
if (Status != ZE_RESULT_SUCCESS) {
std::cerr << "Failed to enable Level Zero tracing\n";
std::terminate();
}
Status = zelTracerSetEpilogues(Tracer, &Epilogue);
if (Status != ZE_RESULT_SUCCESS) {
std::cerr << "Failed to enable Level Zero tracing\n";
std::terminate();
}

Status = zelTracerSetEnabled(Tracer, true);
if (Status != ZE_RESULT_SUCCESS) {
std::cerr << "Failed to enable Level Zero tracing\n";
std::terminate();
}
#endif // XPTI_ENABLE_INSTRUMENTATION
}

void disableZeTracing() {
#ifdef XPTI_ENABLE_INSTRUMENTATION
if (!xptiTraceEnabled())
return;

xptiFinalize(ZE_CALL_STREAM_NAME);
xptiFinalize(ZE_DEBUG_STREAM_NAME);
#endif // XPTI_ENABLE_INSTRUMENTATION
}
40 changes: 40 additions & 0 deletions sycl/plugins/level_zero/ze_api_generator.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
import re
import sys

def camel_to_snake(src):
return re.sub(r'(?<!^)(?=[A-Z])', '_', src).lower()

def snake_to_camel(src):
temp = src.split('_')
return ''.join(x.title() for x in temp)


def extract_ze_apis(header):
"""
Emit file with contents of
_ZE_API(api_name, api_domain, cb, param_type)
"""
api = open("ze_api.def", "w")

matches = re.finditer(r'typedef struct _ze_([_a-z]+)_callbacks_t\n\{\n([a-zA-Z_;\s\n]+)\n\} ze_([_a-z]+)_callbacks_t;', header)

for match in matches:
api_domain = snake_to_camel(match.group(1))
for l in match.group(2).splitlines():
parts = l.split()
api_match = re.match(r'ze_pfn([a-zA-Z]+)Cb_t', parts[0])
api_name_tail = api_match.group(1)
api_name = 'ze' + api_name_tail

param_type = 'ze_' + camel_to_snake(api_name_tail) + '_params_t'

cb = 'pfn' + api_name_tail.replace(api_domain, '') + 'Cb'

api.write("_ZE_API({}, {}, {}, {})\n".format(api_name, api_domain, cb, param_type))

api.close()

if __name__ == "__main__":
with open(sys.argv[1], 'r') as f:
header = f.read()
extract_ze_apis(header)
40 changes: 23 additions & 17 deletions sycl/tools/sycl-prof/collector.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -42,11 +42,11 @@ static Measurements measure() {
return Measurements{TID, PID, TS};
}

XPTI_CALLBACK_API void piBeginEndCallback(uint16_t TraceType,
xpti::trace_event_data_t *,
xpti::trace_event_data_t *,
uint64_t /*Instance*/,
const void *UserData);
XPTI_CALLBACK_API void apiBeginEndCallback(uint16_t TraceType,
xpti::trace_event_data_t *,
xpti::trace_event_data_t *,
uint64_t /*Instance*/,
const void *UserData);
XPTI_CALLBACK_API void taskBeginEndCallback(uint16_t TraceType,
xpti::trace_event_data_t *,
xpti::trace_event_data_t *,
Expand All @@ -71,13 +71,14 @@ XPTI_CALLBACK_API void xptiTraceInit(unsigned int /*major_version*/,
GWriter->init();
}

if (std::string_view(StreamName) == "sycl.pi") {
std::string_view NameView{StreamName};
if (NameView == "sycl.pi") {
uint8_t StreamID = xptiRegisterStream(StreamName);
xptiRegisterCallback(StreamID, xpti::trace_function_begin,
piBeginEndCallback);
apiBeginEndCallback);
xptiRegisterCallback(StreamID, xpti::trace_function_end,
piBeginEndCallback);
} else if (std::string_view(StreamName) == "sycl") {
apiBeginEndCallback);
} else if (NameView == "sycl") {
uint8_t StreamID = xptiRegisterStream(StreamName);
xptiRegisterCallback(StreamID, xpti::trace_task_begin,
taskBeginEndCallback);
Expand All @@ -89,23 +90,28 @@ XPTI_CALLBACK_API void xptiTraceInit(unsigned int /*major_version*/,
waitBeginEndCallback);
xptiRegisterCallback(StreamID, xpti::trace_barrier_end,
waitBeginEndCallback);
} else if (NameView == "sycl.experimental.level_zero.call") {
uint8_t StreamID = xptiRegisterStream(StreamName);
xptiRegisterCallback(StreamID, xpti::trace_function_begin,
apiBeginEndCallback);
xptiRegisterCallback(StreamID, xpti::trace_function_end,
apiBeginEndCallback);
}
}

XPTI_CALLBACK_API void xptiTraceFinish(const char *) { GWriter->finalize(); }

XPTI_CALLBACK_API void piBeginEndCallback(uint16_t TraceType,
xpti::trace_event_data_t *,
xpti::trace_event_data_t *,
uint64_t /*Instance*/,
const void *UserData) {
XPTI_CALLBACK_API void apiBeginEndCallback(uint16_t TraceType,
xpti::trace_event_data_t *,
xpti::trace_event_data_t *,
uint64_t /*Instance*/,
const void *UserData) {
auto [TID, PID, TS] = measure();
if (TraceType == xpti::trace_function_begin) {
GWriter->writeBegin(static_cast<const char *>(UserData), "Plugin", PID, TID,
GWriter->writeBegin(static_cast<const char *>(UserData), "API", PID, TID,
TS);
} else {
GWriter->writeEnd(static_cast<const char *>(UserData), "Plugin", PID, TID,
TS);
GWriter->writeEnd(static_cast<const char *>(UserData), "API", PID, TID, TS);
}
}

Expand Down
1 change: 1 addition & 0 deletions sycl/tools/sycl-prof/main.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,7 @@ int main(int argc, char **argv, char *env[]) {
NewEnv.push_back("XPTI_FRAMEWORK_DISPATCHER=libxptifw.so");
NewEnv.push_back("XPTI_SUBSCRIBERS=libsycl_profiler_collector.so");
NewEnv.push_back("XPTI_TRACE_ENABLE=1");
NewEnv.push_back("ZE_ENABLE_TRACING_LAYER=1");

std::vector<std::string> Args;

Expand Down
Loading