From 488ca1e5f287adea367f828816683767062c2bb9 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Wed, 21 Oct 2026 09:54:57 +0200 Subject: [PATCH 1/2] Add bindings for Intel's PTI library PTI (Profiling Tools Interfaces for GPU) records the Level Zero API calls a process makes and the kernels, copies and fills that execute on the device, much like CUPTI's activity API. The wrappers are generated from PTI_jll's headers like those for Level Zero. PTI calls its buffer callbacks from its own threads, including while the process exits, where Julia code would hang. PTI_jll's libpti_buffers implements them in C instead, and `PTI.foreach_record` processes the queued buffers. The libraries are only loaded when first used. --- Project.toml | 2 + lib/pti/PTI.jl | 73 ++++++ lib/pti/libpti.jl | 559 +++++++++++++++++++++++++++++++++++++++++ res/Project.toml | 1 + res/libpti_prologue.jl | 10 + res/pti.toml | 12 + res/wrap.jl | 4 + src/oneAPI.jl | 2 + 8 files changed, 663 insertions(+) create mode 100644 lib/pti/PTI.jl create mode 100644 lib/pti/libpti.jl create mode 100644 res/libpti_prologue.jl create mode 100644 res/pti.toml diff --git a/Project.toml b/Project.toml index 2057494bb..be8740f00 100644 --- a/Project.toml +++ b/Project.toml @@ -17,6 +17,7 @@ LLVM = "929cbde3-209d-540e-8aea-75f648917ca0" Libdl = "8f399da3-3557-5675-b5ff-fb832c97cbdb" LinearAlgebra = "37e2e46d-f89d-539d-b4ee-838fcccc9c8e" NEO_jll = "700fe977-ac61-5f37-bbc8-c6c4b2b6a9fd" +PTI_jll = "00038326-6c92-5172-8bc1-19e163662d45" PrecompileTools = "aea7be01-6a6a-4083-8856-8a6e6704d82a" Preferences = "21216c6a-2e73-6563-6e65-726566657250" Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" @@ -50,6 +51,7 @@ KernelAbstractions = "0.10" KernelInterface = "0.4" LLVM = "10" NEO_jll = "=26.35.39758" +PTI_jll = "1.2" PrecompileTools = "1" Preferences = "1" SPIRVIntrinsics = "1.4" diff --git a/lib/pti/PTI.jl b/lib/pti/PTI.jl new file mode 100644 index 000000000..43a211139 --- /dev/null +++ b/lib/pti/PTI.jl @@ -0,0 +1,73 @@ +module PTI + +using ..APIUtils + +using CEnum: @cenum + +using PTI_jll + +# PTI_jll does not load its libraries: libpti_view starts a thread once used, and libpti +# hooks into the Level Zero loader. They are only loaded by the first call into them. +is_available() = PTI_jll.is_available() + +include("libpti.jl") + +export PTIError + +struct PTIError <: Exception + code::pti_result +end + +Base.showerror(io::IO, err::PTIError) = + print(io, "PTIError: ", unsafe_string(ptiResultTypeToString(err.code)), + " (code $(Int(err.code)))") + + +## buffer management + +# PTI requests and returns buffers from its own threads, including while the process exits, +# where running Julia code would hang. libpti_buffers implements the callbacks in C, and +# queues the completed buffers for `foreach_record` to process. +const callbacks_set = Ref(false) + +function set_callbacks() + callbacks_set[] && return + ptiViewSetCallbacks(cglobal((:pti_buffers_request, libpti_buffers)), + cglobal((:pti_buffers_complete, libpti_buffers))) + callbacks_set[] = true + return +end + +# Call `f` on a pointer to every record in the completed buffers, which are released +# afterwards. PTI does not document how long the strings that records point to stay valid, +# so `f` should copy anything it needs. +function foreach_record(f) + buf = Ref{Ptr{UInt8}}() + used = Ref{Csize_t}() + record = Ref{Ptr{pti_view_record_base}}() + while ccall((:pti_buffers_pop, libpti_buffers), Cint, + (Ptr{Ptr{UInt8}}, Ptr{Csize_t}), buf, used) == 1 + try + record[] = C_NULL + while true + res = unchecked_ptiViewGetNextRecord(buf[], used[], record) + res == PTI_STATUS_END_OF_BUFFER && break + res == PTI_SUCCESS || throw_api_error(res) + f(record[]) + end + finally + Libc.free(buf[]) + end + end +end + +# Number of buffers whose records were lost because they could not be allocated. +lost_buffers() = ccall((:pti_buffers_lost, libpti_buffers), UInt64, ()) + +function api_name(group, id) + name = Ref{Ptr{Cchar}}() + res = unchecked_ptiViewGetApiIdName(group, id, name) + res == PTI_SUCCESS ? unsafe_string(name[]) : "unknown API $id" +end + +end diff --git a/lib/pti/libpti.jl b/lib/pti/libpti.jl new file mode 100644 index 000000000..a31fa4dbb --- /dev/null +++ b/lib/pti/libpti.jl @@ -0,0 +1,559 @@ +using CEnum: CEnum, @cenum + +# outlined functionality to avoid GC frame allocation +@noinline throw_api_error(res) = throw(PTIError(res)) + +function check(f) + res = f() + if res != PTI_SUCCESS + throw_api_error(res) + end + return +end + +@cenum pti_result::UInt32 begin + PTI_SUCCESS = 0 + PTI_STATUS_END_OF_BUFFER = 1 + PTI_ERROR_NOT_IMPLEMENTED = 2 + PTI_ERROR_BAD_ARGUMENT = 3 + PTI_ERROR_NO_CALLBACKS_SET = 4 + PTI_ERROR_EXTERNAL_ID_QUEUE_EMPTY = 5 + PTI_ERROR_BAD_TIMESTAMP = 6 + PTI_ERROR_BAD_API_ID = 7 + PTI_ERROR_NO_GPU_VIEWS_ENABLED = 8 + PTI_ERROR_DRIVER = 50 + PTI_ERROR_TRACING_NOT_INITIALIZED = 51 + PTI_ERROR_L0_LOCAL_PROFILING_NOT_SUPPORTED = 52 + PTI_ERROR_METRICS_ENABLE_FAILED = 98 + PTI_ERROR_METRICS_RUNTIME_ENABLE_UNSUPPORTED = 99 + PTI_ERROR_METRICS_COLLECTION_NOT_ENABLED = 100 + PTI_ERROR_METRICS_COLLECTION_NOT_DISABLED = 101 + PTI_ERROR_METRICS_COLLECTION_NOT_PAUSED = 102 + PTI_ERROR_METRICS_COLLECTION_ALREADY_PAUSED = 103 + PTI_ERROR_METRICS_COLLECTION_ALREADY_ENABLED = 104 + PTI_ERROR_METRICS_BAD_COLLECTION_CONFIGURATION = 105 + PTI_ERROR_METRICS_NO_DATA_COLLECTED = 106 + PTI_ERROR_METRICS_SCOPE_METRIC_NOT_FOUND = 151 + PTI_ERROR_METRICS_SCOPE_NOT_A_SINGLE_GROUP = 152 + PTI_ERROR_METRICS_SCOPE_OUT_OF_MEMORY = 153 + PTI_ERROR_METRICS_SCOPE_COLLECTION_BUFFER_TOO_SMALL = 154 + PTI_ERROR_METRICS_SCOPE_INSUFFICIENT_BUFFER = 155 + PTI_ERROR_METRICS_SCOPE_INVALID_COLLECTION_BUFFER = 156 + PTI_WARN_METRICS_SCOPE_PARTIAL_BUFFER = 157 + PTI_WARN_BUFFER_NOT_FINALIZED = 158 + PTI_ERROR_METRICS_SCOPE_DEVICE_TYPE_NOT_UNIFORM = 159 + PTI_ERROR_INTERNAL = 200 + PTI_ERROR_PC_SAMPLING_ALREADY_ENABLED = 250 + PTI_ERROR_PC_SAMPLING_NOT_CONFIGURED = 251 + PTI_ERROR_PC_SAMPLING_ALREADY_CONFIGURED = 252 + PTI_ERROR_PC_SAMPLING_ALREADY_STARTED = 253 + PTI_ERROR_PC_SAMPLING_NOT_STARTED = 254 + PTI_ERROR_PC_SAMPLING_ALREADY_STOPPED = 255 + PTI_ERROR_PC_SAMPLING_NOT_STOPPED = 256 + PTI_ERROR_PC_SAMPLING_UNSUPPORTED = 257 + PTI_ERROR_PC_SAMPLING_CONFIGURATION_FAIL = 258 + PTI_RESULT_FORCE_UINT32 = 2147483647 +end + +function ptiResultTypeToString(result_value) + @gcsafe_ccall libpti_view.ptiResultTypeToString(result_value::pti_result)::Ptr{Cchar} +end + +const pti_device_handle_t = Ptr{Cvoid} + +const pti_backend_ctx_t = Ptr{Cvoid} + +const pti_backend_queue_t = Ptr{Cvoid} + +const pti_backend_evt_t = Ptr{Cvoid} + +const pti_backend_command_list_t = Ptr{Cvoid} + +const pti_backend_kernel_t = Ptr{Cvoid} + +const pti_backend_module_t = Ptr{Cvoid} + +struct pti_version + _major::UInt32 + _minor::UInt32 + _patch::UInt32 +end + +function ptiVersionString() + @gcsafe_ccall libpti_view.ptiVersionString()::Ptr{Cchar} +end + +function ptiVersion() + @gcsafe_ccall libpti_view.ptiVersion()::pti_version +end + +@cenum _pti_view_kind::UInt32 begin + PTI_VIEW_INVALID = 0 + PTI_VIEW_DEVICE_GPU_KERNEL = 1 + PTI_VIEW_DEVICE_CPU_KERNEL = 2 + PTI_VIEW_DRIVER_API = 3 + PTI_VIEW_RESERVED = 4 + PTI_VIEW_COLLECTION_OVERHEAD = 5 + PTI_VIEW_RUNTIME_API = 6 + PTI_VIEW_EXTERNAL_CORRELATION = 7 + PTI_VIEW_DEVICE_GPU_MEM_COPY = 8 + PTI_VIEW_DEVICE_GPU_MEM_FILL = 9 + PTI_VIEW_DEVICE_GPU_MEM_COPY_P2P = 10 + PTI_VIEW_DEVICE_SYNCHRONIZATION = 11 + PTI_VIEW_COMMUNICATION = 12 + PTI_VIEW_KIND_FORCE_UINT32 = 2147483647 +end + +const pti_view_kind = _pti_view_kind + +@cenum _pti_view_synchronization_type::UInt32 begin + PTI_VIEW_SYNCHRONIZATION_TYPE_UNKNOWN = 0 + PTI_VIEW_SYNCHRONIZATION_TYPE_GPU_BARRIER_EXECUTION = 1 + PTI_VIEW_SYNCHRONIZATION_TYPE_GPU_BARRIER_MEMORY = 2 + PTI_VIEW_SYNCHRONIZATION_TYPE_HOST_FENCE = 3 + PTI_VIEW_SYNCHRONIZATION_TYPE_HOST_EVENT = 4 + PTI_VIEW_SYNCHRONIZATION_TYPE_HOST_COMMAND_LIST = 5 + PTI_VIEW_SYNCHRONIZATION_TYPE_HOST_COMMAND_QUEUE = 6 + PTI_VIEW_SYNCHRONIZATION_TYPE_HOST_DEVICE = 7 + PTI_VIEW_SYNCHRONIZATION_TYPE_FORCE_UINT32 = 2147483647 +end + +const pti_view_synchronization_type = _pti_view_synchronization_type + +@cenum _pti_view_memory_type::UInt32 begin + PTI_VIEW_MEMORY_TYPE_MEMORY = 0 + PTI_VIEW_MEMORY_TYPE_HOST = 1 + PTI_VIEW_MEMORY_TYPE_DEVICE = 2 + PTI_VIEW_MEMORY_TYPE_SHARED = 3 + PTI_VIEW_MEMORY_TYPE_FORCE_UINT32 = 2147483647 +end + +const pti_view_memory_type = _pti_view_memory_type + +@cenum _pti_view_memcpy_type::UInt32 begin + PTI_VIEW_MEMCPY_TYPE_M2M = 0 + PTI_VIEW_MEMCPY_TYPE_M2H = 1 + PTI_VIEW_MEMCPY_TYPE_M2D = 2 + PTI_VIEW_MEMCPY_TYPE_M2S = 3 + PTI_VIEW_MEMCPY_TYPE_H2M = 4 + PTI_VIEW_MEMCPY_TYPE_H2H = 5 + PTI_VIEW_MEMCPY_TYPE_H2D = 6 + PTI_VIEW_MEMCPY_TYPE_H2S = 7 + PTI_VIEW_MEMCPY_TYPE_D2M = 8 + PTI_VIEW_MEMCPY_TYPE_D2H = 9 + PTI_VIEW_MEMCPY_TYPE_D2D = 10 + PTI_VIEW_MEMCPY_TYPE_D2S = 11 + PTI_VIEW_MEMCPY_TYPE_S2M = 12 + PTI_VIEW_MEMCPY_TYPE_S2H = 13 + PTI_VIEW_MEMCPY_TYPE_S2D = 14 + PTI_VIEW_MEMCPY_TYPE_S2S = 15 + PTI_VIEW_MEMCPY_TYPE_FORCE_UINT32 = 2147483647 +end + +const pti_view_memcpy_type = _pti_view_memcpy_type + +@cenum _pti_view_external_kind::UInt32 begin + PTI_VIEW_EXTERNAL_KIND_INVALID = 0 + PTI_VIEW_EXTERNAL_KIND_UNKNOWN = 1 + PTI_VIEW_EXTERNAL_KIND_CUSTOM_0 = 2 + PTI_VIEW_EXTERNAL_KIND_CUSTOM_1 = 3 + PTI_VIEW_EXTERNAL_KIND_CUSTOM_2 = 4 + PTI_VIEW_EXTERNAL_KIND_CUSTOM_3 = 5 + PTI_VIEW_EXTERNAL_KIND_FORCE_UINT32 = 2147483647 +end + +const pti_view_external_kind = _pti_view_external_kind + +@cenum _pti_view_overhead_kind::UInt32 begin + PTI_VIEW_OVERHEAD_KIND_INVALID = 0 + PTI_VIEW_OVERHEAD_KIND_UNKNOWN = 1 + PTI_VIEW_OVERHEAD_KIND_RESOURCE = 2 + PTI_VIEW_OVERHEAD_KIND_BUFFER_FLUSH = 3 + PTI_VIEW_OVERHEAD_KIND_DRIVER = 4 + PTI_VIEW_OVERHEAD_KIND_TIME = 5 + PTI_VIEW_OVERHEAD_KIND_FORCE_UINT32 = 2147483647 +end + +const pti_view_overhead_kind = _pti_view_overhead_kind + +@cenum _pti_api_group_id::UInt32 begin + PTI_API_GROUP_RESERVED = 0 + PTI_API_GROUP_LEVELZERO = 1 + PTI_API_GROUP_OPENCL = 2 + PTI_API_GROUP_SYCL = 3 + PTI_API_GROUP_HYBRID_SYCL_LEVELZERO = 4 + PTI_API_GROUP_HYBRID_SYCL_OPENCL = 5 + PTI_API_GROUP_ALL = 2147483647 +end + +const pti_api_group_id = _pti_api_group_id + +@cenum _pti_api_class::UInt32 begin + PTI_API_CLASS_RESERVED = 0 + PTI_API_CLASS_GPU_OPERATION_CORE = 1 + PTI_API_CLASS_HOST_OPERATION_SYNCHRONIZATION = 2 + PTI_API_CLASS_ALL = 2147483647 +end + +const pti_api_class = _pti_api_class + +struct pti_view_record_base + _view_kind::pti_view_kind +end + +struct pti_view_record_kernel + _view_kind::pti_view_record_base + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _source_file_name::Ptr{Cchar} + _source_line_number::UInt64 + _kernel_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _pci_address::NTuple{16,Cchar} + _device_uuid::NTuple{16,UInt8} + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _sycl_task_begin_timestamp::UInt64 + _sycl_enqk_begin_timestamp::UInt64 + _sycl_node_id::UInt64 + _sycl_queue_id::UInt64 + _sycl_invocation_id::UInt32 +end + +struct pti_view_record_kernel_v2 + _view_kind::pti_view_record_base + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _source_file_name::Ptr{Cchar} + _source_line_number::UInt64 + _kernel_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _pci_address::NTuple{16,Cchar} + _device_uuid::NTuple{16,UInt8} + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _sycl_task_begin_timestamp::UInt64 + _sycl_enqk_begin_timestamp::UInt64 + _sycl_node_id::UInt64 + _sycl_queue_id::UInt64 + _sycl_invocation_id::UInt32 + _device_handle::pti_device_handle_t + _engine_ordinal::UInt32 + _engine_index::UInt32 +end + +struct pti_view_record_synchronization + _view_kind::pti_view_record_base + _synch_type::pti_view_synchronization_type + _context_handle::pti_backend_ctx_t + _queue_handle::pti_backend_queue_t + _event_handle::pti_backend_evt_t + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _thread_id::UInt32 + _correlation_id::UInt32 + _number_wait_events::UInt32 + _return_code::UInt32 + _api_id::UInt32 + _api_group::pti_api_group_id +end + +struct pti_view_record_memory_copy + _view_kind::pti_view_record_base + _memcpy_type::pti_view_memcpy_type + _mem_src::pti_view_memory_type + _mem_dst::pti_view_memory_type + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _pci_address::NTuple{16,Cchar} + _device_uuid::NTuple{16,UInt8} + _mem_op_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _bytes::UInt64 + _sycl_queue_id::UInt64 +end + +struct pti_view_record_memory_copy_v2 + _view_kind::pti_view_record_base + _memcpy_type::pti_view_memcpy_type + _mem_src::pti_view_memory_type + _mem_dst::pti_view_memory_type + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _pci_address::NTuple{16,Cchar} + _device_uuid::NTuple{16,UInt8} + _mem_op_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _bytes::UInt64 + _sycl_queue_id::UInt64 + _device_handle::pti_device_handle_t + _engine_ordinal::UInt32 + _engine_index::UInt32 +end + +struct pti_view_record_memory_copy_p2p + _view_kind::pti_view_record_base + _memcpy_type::pti_view_memcpy_type + _mem_src::pti_view_memory_type + _mem_dst::pti_view_memory_type + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _src_pci_address::NTuple{16,Cchar} + _dst_pci_address::NTuple{16,Cchar} + _src_uuid::NTuple{16,UInt8} + _dst_uuid::NTuple{16,UInt8} + _mem_op_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _bytes::UInt64 + _sycl_queue_id::UInt64 +end + +struct pti_view_record_memory_copy_p2p_v2 + _view_kind::pti_view_record_base + _memcpy_type::pti_view_memcpy_type + _mem_src::pti_view_memory_type + _mem_dst::pti_view_memory_type + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _src_pci_address::NTuple{16,Cchar} + _dst_pci_address::NTuple{16,Cchar} + _src_uuid::NTuple{16,UInt8} + _dst_uuid::NTuple{16,UInt8} + _mem_op_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _bytes::UInt64 + _sycl_queue_id::UInt64 + _src_device_handle::pti_device_handle_t + _dst_device_handle::pti_device_handle_t + _engine_ordinal::UInt32 + _engine_index::UInt32 +end + +struct pti_view_record_memory_fill + _view_kind::pti_view_record_base + _mem_type::pti_view_memory_type + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _pci_address::NTuple{16,Cchar} + _device_uuid::NTuple{16,UInt8} + _mem_op_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _bytes::UInt64 + _value_for_set::UInt64 + _sycl_queue_id::UInt64 +end + +struct pti_view_record_memory_fill_v2 + _view_kind::pti_view_record_base + _mem_type::pti_view_memory_type + _queue_handle::pti_backend_queue_t + _context_handle::pti_backend_ctx_t + _name::Ptr{Cchar} + _pci_address::NTuple{16,Cchar} + _device_uuid::NTuple{16,UInt8} + _mem_op_id::UInt64 + _correlation_id::UInt32 + _thread_id::UInt32 + _append_timestamp::UInt64 + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _submit_timestamp::UInt64 + _bytes::UInt64 + _value_for_set::UInt64 + _sycl_queue_id::UInt64 + _device_handle::pti_device_handle_t + _engine_ordinal::UInt32 + _engine_index::UInt32 +end + +struct pti_view_record_external_correlation + _view_kind::pti_view_record_base + _correlation_id::UInt32 + _external_id::UInt64 + _external_kind::pti_view_external_kind +end + +struct pti_view_record_overhead + _view_kind::pti_view_record_base + _overhead_start_timestamp_ns::UInt64 + _overhead_end_timestamp_ns::UInt64 + _overhead_thread_id::UInt32 + _api_id::UInt32 + _overhead_count::UInt64 + _overhead_duration_ns::UInt64 + _overhead_kind::pti_view_overhead_kind +end + +struct pti_view_record_api + _view_kind::pti_view_record_base + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _api_group::pti_api_group_id + _api_id::UInt32 + _process_id::UInt32 + _thread_id::UInt32 + _correlation_id::UInt32 + _return_code::UInt32 +end + +struct pti_view_record_comms + _view_kind::pti_view_record_base + _start_timestamp::UInt64 + _end_timestamp::UInt64 + _process_id::UInt32 + _thread_id::UInt32 + _send_size::UInt64 + _recv_size::UInt64 + _communicator_id::UInt64 + _name::Ptr{Cchar} +end + +# typedef void ( * pti_fptr_buffer_completed ) ( unsigned char * buffer , size_t buffer_size_in_bytes , size_t used_bytes ) +const pti_fptr_buffer_completed = Ptr{Cvoid} + +# typedef void ( * pti_fptr_buffer_requested ) ( unsigned char * * buffer_ptr , size_t * buffer_size_in_bytes ) +const pti_fptr_buffer_requested = Ptr{Cvoid} + +@checked function ptiViewSetCallbacks(fptr_bufferRequested, fptr_bufferCompleted) + @gcsafe_ccall libpti_view.ptiViewSetCallbacks(fptr_bufferRequested::pti_fptr_buffer_requested, + fptr_bufferCompleted::pti_fptr_buffer_completed)::pti_result +end + +@checked function ptiViewEnable(view_kind) + @gcsafe_ccall libpti_view.ptiViewEnable(view_kind::pti_view_kind)::pti_result +end + +@checked function ptiViewDisable(view_kind) + @gcsafe_ccall libpti_view.ptiViewDisable(view_kind::pti_view_kind)::pti_result +end + +@checked function ptiViewGPULocalAvailable() + @gcsafe_ccall libpti_view.ptiViewGPULocalAvailable()::pti_result +end + +@checked function ptiFlushAllViews() + @gcsafe_ccall libpti_view.ptiFlushAllViews()::pti_result +end + +@checked function ptiViewGetNextRecord(buffer, valid_bytes, record) + @gcsafe_ccall libpti_view.ptiViewGetNextRecord(buffer::Ptr{UInt8}, valid_bytes::Csize_t, + record::Ptr{Ptr{pti_view_record_base}})::pti_result +end + +@checked function ptiViewPushExternalCorrelationId(external_kind, external_id) + @gcsafe_ccall libpti_view.ptiViewPushExternalCorrelationId(external_kind::pti_view_external_kind, + external_id::UInt64)::pti_result +end + +@checked function ptiViewPopExternalCorrelationId(external_kind, p_external_id) + @gcsafe_ccall libpti_view.ptiViewPopExternalCorrelationId(external_kind::pti_view_external_kind, + p_external_id::Ptr{UInt64})::pti_result +end + +function ptiViewOverheadKindToString(type) + @gcsafe_ccall libpti_view.ptiViewOverheadKindToString(type::pti_view_overhead_kind)::Ptr{Cchar} +end + +function ptiViewMemoryTypeToString(type) + @gcsafe_ccall libpti_view.ptiViewMemoryTypeToString(type::pti_view_memory_type)::Ptr{Cchar} +end + +function ptiViewMemcpyTypeToString(type) + @gcsafe_ccall libpti_view.ptiViewMemcpyTypeToString(type::pti_view_memcpy_type)::Ptr{Cchar} +end + +function ptiViewGetTimestamp() + @gcsafe_ccall libpti_view.ptiViewGetTimestamp()::UInt64 +end + +# typedef uint64_t ( * pti_fptr_get_timestamp ) ( void ) +const pti_fptr_get_timestamp = Ptr{Cvoid} + +@checked function ptiViewSetTimestampCallback(fptr_timestampRequested) + @gcsafe_ccall libpti_view.ptiViewSetTimestampCallback(fptr_timestampRequested::pti_fptr_get_timestamp)::pti_result +end + +@checked function ptiViewGetApiIdName(type, unique_id, name) + @gcsafe_ccall libpti_view.ptiViewGetApiIdName(type::pti_api_group_id, unique_id::UInt32, + name::Ptr{Ptr{Cchar}})::pti_result +end + +@checked function ptiViewEnableDriverApi(enable, api_group_id, api_id) + @gcsafe_ccall libpti_view.ptiViewEnableDriverApi(enable::UInt32, + api_group_id::pti_api_group_id, + api_id::UInt32)::pti_result +end + +@checked function ptiViewEnableRuntimeApi(enable, api_group_id, api_id) + @gcsafe_ccall libpti_view.ptiViewEnableRuntimeApi(enable::UInt32, + api_group_id::pti_api_group_id, + api_id::UInt32)::pti_result +end + +@checked function ptiViewEnableDriverApiClass(enable, api_class, group) + @gcsafe_ccall libpti_view.ptiViewEnableDriverApiClass(enable::UInt32, + api_class::pti_api_class, + group::pti_api_group_id)::pti_result +end + +@checked function ptiViewEnableRuntimeApiClass(enable, api_class, group) + @gcsafe_ccall libpti_view.ptiViewEnableRuntimeApiClass(enable::UInt32, + api_class::pti_api_class, + group::pti_api_group_id)::pti_result +end + +const PTI_MAX_DEVICE_UUID_SIZE = 16 + +# Skipping MacroDefinition: PTI_VERSION 1.2.0 + +const PTI_VERSION_STRING = "1.2.0" + +const PTI_VERSION_MAJOR = 1 + +const PTI_VERSION_MINOR = 2 + +const PTI_VERSION_PATCH = 0 + +const PTI_COMMIT_HASH_STRING = "fdc44f65ccfc4c75f951a8f01b1ef9326223aaaf" + +const PTI_MAX_PCI_ADDRESS_SIZE = 16 + +const PTI_INVALID_QUEUE_ID = 0xffffffffffffffff - 1 diff --git a/res/Project.toml b/res/Project.toml index f7b4a7fec..af02f52ab 100644 --- a/res/Project.toml +++ b/res/Project.toml @@ -1,4 +1,5 @@ [deps] Clang = "40e3b903-d033-50b4-a0cc-940c62c95e31" JuliaFormatter = "98e50ef6-434e-11e9-1051-2b60c6c9e899" +PTI_jll = "00038326-6c92-5172-8bc1-19e163662d45" oneAPI_Level_Zero_Headers_jll = "f4bc562b-d309-54f8-9efb-476e56f0410d" diff --git a/res/libpti_prologue.jl b/res/libpti_prologue.jl new file mode 100644 index 000000000..7cb503b72 --- /dev/null +++ b/res/libpti_prologue.jl @@ -0,0 +1,10 @@ +# outlined functionality to avoid GC frame allocation +@noinline throw_api_error(res) = throw(PTIError(res)) + +function check(f) + res = f() + if res != PTI_SUCCESS + throw_api_error(res) + end + return +end diff --git a/res/pti.toml b/res/pti.toml new file mode 100644 index 000000000..150207c16 --- /dev/null +++ b/res/pti.toml @@ -0,0 +1,12 @@ +[general] +library_name = "libpti_view" +output_file_path = "../lib/pti/libpti.jl" +prologue_file_path = "./libpti_prologue.jl" + + +[codegen] +use_ccall_macro = true + +[api] +checked_rettypes = [ "pti_result" ] +gcsafe = true diff --git a/res/wrap.jl b/res/wrap.jl index c9ec479a3..53ad3a57b 100644 --- a/res/wrap.jl +++ b/res/wrap.jl @@ -115,6 +115,7 @@ end # using oneAPI_Level_Zero_Headers_jll +using PTI_jll function main() wrap("ze", oneAPI_Level_Zero_Headers_jll.ze_api) @@ -126,6 +127,9 @@ function main() dependents=false, include_dirs=[dirname(dirname(oneAPI_Level_Zero_Headers_jll.ze_api))] ) + pti_include = joinpath(PTI_jll.artifact_dir, "include") + wrap("pti", (joinpath(pti_include, "pti", "$name.h") for name in ("pti", "pti_version", "pti_view"))...; + dependents=false, include_dirs=[pti_include]) end isinteractive() || main() diff --git a/src/oneAPI.jl b/src/oneAPI.jl index a55a550f4..fd5569a4a 100644 --- a/src/oneAPI.jl +++ b/src/oneAPI.jl @@ -77,6 +77,8 @@ include("random.jl") include("utils.jl") include("profile.jl") +include("../lib/pti/PTI.jl") + include("oneAPIKernels.jl") import .oneAPIKernels: oneAPIBackend export oneAPIBackend From 8135b8581ff4c8420d5d8477735a6336312f9634 Mon Sep 17 00:00:00 2001 From: Tim Besard Date: Wed, 21 Oct 2026 09:55:06 +0200 Subject: [PATCH 2/2] Add an integrated profiler to `oneAPI.@profile` Without `external=true`, `oneAPI.@profile` now collects the activity of the given code with PTI, and shows the Level Zero API calls made by the host and the kernels, copies and fills that executed on the device, as a summary or, with `trace=true`, as a chronological trace in which correlation IDs link the API calls to the operations they submitted. This includes the work that oneAPI.jl batches and the work that oneMKL submits. `oneAPI.@bprofile` runs code repeatedly and reports the aggregated results. Like CUDA.jl, `oneAPI.@profile` defaults to the external profiler when Julia runs under one. The display code is adapted from Metal.jl's profiler. --- Project.toml | 6 + docs/src/usage/profiling.md | 84 +++++-- src/oneAPI.jl | 4 +- src/profile.jl | 134 +++++++++-- src/profiling.jl | 438 ++++++++++++++++++++++++++++++++++++ test/profile.jl | 93 +++++++- 6 files changed, 716 insertions(+), 43 deletions(-) create mode 100644 src/profiling.jl diff --git a/Project.toml b/Project.toml index be8740f00..64be93bfa 100644 --- a/Project.toml +++ b/Project.toml @@ -7,6 +7,7 @@ version = "2.9.2" AbstractFFTs = "621f4979-c628-5d54-868e-fcf4e3e8185c" Adapt = "79e6a3ab-5dfb-504d-930d-738a2a938a0e" CEnum = "fa961155-64e5-5f13-b03f-caf6b980ea82" +Crayons = "a8cc5b0e-0ffa-5ad4-8c14-923d3ee1735f" ExprTools = "e2ba6199-217a-4e67-a87a-7c52f15ade04" GPUArrays = "0c68f7d7-f131-5f86-a1c3-88cf8149b2d7" GPUCompiler = "61eb1bfa-7361-4325-ad38-22787b887f55" @@ -19,6 +20,7 @@ LinearAlgebra = "37e2e46d-f89d-539d-b4ee-838fcccc9c8e" NEO_jll = "700fe977-ac61-5f37-bbc8-c6c4b2b6a9fd" PTI_jll = "00038326-6c92-5172-8bc1-19e163662d45" PrecompileTools = "aea7be01-6a6a-4083-8856-8a6e6704d82a" +PrettyTables = "08abe8d2-0d0c-5749-adfa-8a2ac140af0d" Preferences = "21216c6a-2e73-6563-6e65-726566657250" Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" Random = "9a3f8284-a2c9-5f02-9a11-845980a1fd5c" @@ -28,6 +30,7 @@ SPIRV_LLVM_Translator_jll = "4a5d46fc-d8cf-5151-a261-86b458210efb" SPIRV_Tools_jll = "6ac6d60f-d740-5983-97d7-a4482c0689f4" SparseArrays = "2f01184e-e22b-5df5-ae63-d93ebab69eaf" SpecialFunctions = "276daf66-3868-5448-9aa4-cd146d93841b" +Statistics = "10745b16-79ce-11e8-11f9-7d13ad32a3b2" oneAPI_Level_Zero_Headers_jll = "f4bc562b-d309-54f8-9efb-476e56f0410d" oneAPI_Level_Zero_Loader_jll = "13eca655-d68d-5b81-8367-6d99d727ab01" oneAPI_Support_jll = "b049733a-a71d-5ed3-8eba-7d323ac00b36" @@ -42,6 +45,7 @@ KernelAbstractionsExt = "KernelAbstractions" AbstractFFTs = "1.5.0" Adapt = "4" CEnum = "0.5, 1" +Crayons = "4" ExprTools = "0.1" GPUArrays = "12.1" GPUCompiler = "2.13" @@ -53,12 +57,14 @@ LLVM = "10" NEO_jll = "=26.35.39758" PTI_jll = "1.2" PrecompileTools = "1" +PrettyTables = "3" Preferences = "1" SPIRVIntrinsics = "1.4" SPIRV_LLVM_Backend_jll = "23" SPIRV_LLVM_Translator_jll = "23" SPIRV_Tools_jll = "2025.4.0" SpecialFunctions = "1.3, 2" +Statistics = "1" julia = "1.10" oneAPI_Level_Zero_Loader_jll = "1.32" oneAPI_Support_jll = "0.11.0" diff --git a/docs/src/usage/profiling.md b/docs/src/usage/profiling.md index f12646a2f..1c5727c14 100644 --- a/docs/src/usage/profiling.md +++ b/docs/src/usage/profiling.md @@ -1,17 +1,75 @@ # Profiling -To find out where a GPU application spends its time, run it under an external profiler, -such as Intel's [unitrace](https://github.com/intel/pti-gpu/tree/master/tools/unitrace) -or VTune. These record the Level Zero API calls the application makes and the time each -kernel and memory copy takes to execute on the device. +To find out where a GPU application spends its time, use oneAPI.jl's integrated profiler, +or an external profiler such as Intel's +[unitrace](https://github.com/intel/pti-gpu/tree/master/tools/unitrace) or VTune. For simple timing measurements, see [Benchmarking](@ref) in the Performance Guide. -## Restricting collection +## Integrated profiler -Profiling a whole Julia session also captures compilation and other warm-up work. To only -collect a region of interest, start the profiler paused and wrap that region in -`oneAPI.@profile external=true`: +`oneAPI.@profile` runs code and reports the Level Zero API calls the host made, and the +kernels, memory copies and fills that executed on the GPU. It uses Intel's Profiling Tools +Interfaces for GPU (PTI), so it also covers work submitted by libraries such as oneMKL. +Run the code once beforehand, so that compilation does not end up in the profile: + +```julia +julia> a = oneArray(rand(Float32, 1024, 1024)); b = similar(a); + +julia> c = a * a; copyto!(b, c); # warm up + +julia> oneAPI.@profile begin + c = a * a + copyto!(b, c) + end +Profiled over 5.1 ms. + +Host-side activity: 33 Level Zero API calls taking 1.22 ms (24.02% of wall-clock) +┌──────────┬────────────┬───────┬──────────────────────────────────────┬───────────────────────────────────┐ +│ Time (%) │ Total time │ Calls │ Time distribution │ Name │ +├──────────┼────────────┼───────┼──────────────────────────────────────┼───────────────────────────────────┤ +│ 13.38% │ 681.99 µs │ 4 │ 170.5 µs ± 340.57 ( 0.11 ‥ 681.35) │ zeCommandQueueSynchronize │ +│ 5.61% │ 286.14 µs │ 1 │ │ zeContextMakeMemoryResident │ +│ 2.50% │ 127.69 µs │ 1 │ │ zeCommandQueueExecuteCommandLists │ +│ 0.85% │ 43.27 µs │ 1 │ │ zeMemAllocDevice │ +│ 0.81% │ 41.14 µs │ 1 │ │ zeCommandListAppendMemoryCopy │ +│ 0.40% │ 20.49 µs │ 1 │ │ zeCommandListReset │ +│ 0.27% │ 13.74 µs │ 1 │ │ zeCommandListAppendLaunchKernel │ +│ 0.08% │ 3.88 µs │ 1 │ │ zeDeviceGetProperties │ +│ 0.06% │ 2.91 µs │ 15 │ 194.0 ns ± 410.03 ( 30.0 ‥ 1580.0) │ zeKernelSetArgumentValue │ +│ 0.03% │ 1.72 µs │ 1 │ │ zeEventHostReset │ +│ 0.01% │ 740.0 ns │ 1 │ │ zeCommandListClose │ +│ 0.01% │ 420.0 ns │ 3 │ 140.0 ns ± 140.0 ( 40.0 ‥ 300.0) │ zeMemGetAllocProperties │ +│ 0.00% │ 200.0 ns │ 1 │ │ zeKernelSetGroupSize │ +│ 0.00% │ 120.0 ns │ 1 │ │ zeFenceReset │ +└──────────┴────────────┴───────┴──────────────────────────────────────┴───────────────────────────────────┘ + +Device-side activity: GPU was busy for 551.25 µs (10.81% of wall-clock) +┌──────────┬────────────┬───────┬────────────────────────────────────┐ +│ Time (%) │ Total time │ Calls │ Name │ +├──────────┼────────────┼───────┼────────────────────────────────────┤ +│ 9.80% │ 499.48 µs │ 1 │ sgemm_nocopy_nn_16x16_8x4 │ +│ 1.02% │ 51.77 µs │ 1 │ zeCommandListAppendMemoryCopy(D2D) │ +└──────────┴────────────┴───────┴────────────────────────────────────┘ +``` + +With `trace=true`, the profiler lists every API call and GPU operation in chronological +order instead. Their ID column links each GPU operation to the API call that submitted it. +To profile code that runs quickly, `oneAPI.@bprofile` runs it repeatedly for a second (or +`time` seconds) and reports the aggregated results. + +The integrated profiler is only available on x86_64 Linux. + +```@docs +oneAPI.@profile +oneAPI.@bprofile +``` + +## External profilers + +External profilers offer more detail, such as hardware metrics. Profiling a whole Julia +session also captures compilation and other warm-up work, so to only collect a region of +interest, start the profiler paused and wrap that region in `oneAPI.@profile external=true`: ```julia using oneAPI @@ -26,11 +84,9 @@ oneAPI.@profile external=true begin end ``` -```@docs -oneAPI.@profile -``` +When Julia runs under an external profiler, `oneAPI.@profile` defaults to `external=true`. -## Launching the profiler +### Launching the profiler oneAPI.jl uses the Level Zero loader and the Intel GPU driver from its own artifacts. An external profiler that loads into the process before Julia starts may pick up another copy @@ -55,7 +111,7 @@ eval "$(julia --project -e ' This is not needed when oneAPI.jl is configured to use the system libraries (see [Using System Libraries (Advanced)](@ref)). -### unitrace +#### unitrace unitrace is part of Intel's [PTI-GPU](https://github.com/intel/pti-gpu) tools. Start it with `--start-paused` so that only the code in `oneAPI.@profile external=true` is @@ -69,7 +125,7 @@ unitrace --start-paused --device-timing --chrome-kernel-logging \ `--device-timing` prints a summary of kernel and memory copy times when the application exits; the Chrome trace can be opened in [Perfetto](https://ui.perfetto.dev). -### VTune +#### VTune VTune finds the ITT collector through the `INTEL_LIBITTNOTIFY64` environment variable, which it sets for applications it launches. Start the collection paused: diff --git a/src/oneAPI.jl b/src/oneAPI.jl index fd5569a4a..184a38ee9 100644 --- a/src/oneAPI.jl +++ b/src/oneAPI.jl @@ -75,9 +75,11 @@ end include("broadcast.jl") include("random.jl") include("utils.jl") -include("profile.jl") +# profiling include("../lib/pti/PTI.jl") +include("profiling.jl") +include("profile.jl") include("oneAPIKernels.jl") import .oneAPIKernels: oneAPIBackend diff --git a/src/profile.jl b/src/profile.jl index b8934a09e..74d75e747 100644 --- a/src/profile.jl +++ b/src/profile.jl @@ -1,52 +1,142 @@ # Profiler control """ + oneAPI.@profile [trace=false] [raw=false] code... oneAPI.@profile external=true code... -Profile the GPU execution of `code` with an external profiler, such as Intel's -[unitrace](https://github.com/intel/pti-gpu/tree/master/tools/unitrace) or VTune. +Profile the GPU execution of `code`. -Collection is restricted to `code` using the Instrumentation and Tracing Technology (ITT) -API: the profiler is resumed before `code` runs and paused afterwards, so it should be -started in paused mode (e.g. `unitrace --start-paused`). Work submitted to the calling -task's stream is synchronized before resuming and after `code`, so that it is attributed -to the right side of the boundary; work on other streams or devices is not waited for. +There are two modes of operation, depending on whether `external` is `true` or `false`. +The default value depends on whether Julia is being run under an external profiler. -When no profiler is attached, `code` still runs, and a warning is shown. +## Integrated profiler (`external=false`, the default) + +oneAPI.jl collects the activity of `code` using Intel's Profiling Tools Interfaces for GPU +(PTI), and displays two tables: + + - **Host-side activity**: the Level Zero API calls made while running `code`, by + oneAPI.jl and by libraries such as oneMKL, grouped by function and sorted by time. + - **Device-side activity**: the kernels, memory copies and fills that executed on the + GPU, grouped by name. + +To display a chronological trace instead, set `trace` to `true`. The ID column then links +API calls to the GPU operations they submitted. Calls that poll for the completion of GPU +work are hidden when the work was not done yet, unless `raw` is set to `true`. + +Slow entries are highlighted: yellow is among the slowest 25%, red among the slowest 5%. + +Work submitted to the calling task's stream is synchronized before and after `code`, so +the profile covers its execution. The profile can also contain work from other tasks. +GPU operations may overlap in time, so the device-side percentages are relative to the +wall-clock time of `code`, not to the sum of the durations. + +## External profilers (`external=true`, when an external profiler is detected) + +For more advanced profiling, use an external profiler such as Intel's +[unitrace](https://github.com/intel/pti-gpu/tree/master/tools/unitrace) or VTune. When +started in paused mode (e.g. `unitrace --start-paused`), wrapping code in +`oneAPI.@profile external=true` restricts collection to that code, using the +Instrumentation and Tracing Technology (ITT) API. Work submitted to the calling task's +stream is synchronized before resuming the profiler and after `code`, so that it is +attributed to the right side of the boundary; work on other streams or devices is not +waited for. When no profiler is attached, `code` still runs, and a warning is shown. See the profiling page of the documentation for how to launch Julia under an external profiler. - -!!! note - Integrated profiling, where oneAPI.jl collects and displays the results itself, is - not supported yet, so `external=true` is required. """ macro profile(ex...) code = ex[end] kwargs = ex[1:end-1] - external = false + external = quote + if $itt_collector() + @info "This Julia session is being profiled by an external profiler; defaulting to `oneAPI.@profile external=true`." maxlog=1 _id=:oneapi_profile_external + true + else + false + end + end + explicit_external = false + remaining = Expr[] for kwarg in kwargs - if Meta.isexpr(kwarg, :(=)) && kwarg.args[1] === :external - value = kwarg.args[2] + Meta.isexpr(kwarg, :(=)) || + throw(ArgumentError("Invalid keyword argument to oneAPI.@profile: $kwarg")) + key, value = kwarg.args + if key === :external isa(value, Bool) || throw(ArgumentError("Invalid value for keyword argument `external`: got `$value`, expected literal boolean value")) external = value + explicit_external = value + elseif key in (:trace, :raw) + push!(remaining, Expr(:kw, key, esc(value))) else throw(ArgumentError("Invalid keyword argument to oneAPI.@profile: $kwarg")) end end - external || throw(ArgumentError("oneAPI.@profile does not support integrated profiling yet; use `oneAPI.@profile external=true` under an external profiler")) + if explicit_external && !isempty(remaining) + throw(ArgumentError("oneAPI.@profile external=true does not support other keyword arguments")) + end quote profiled_code() = $(esc(code)) - $profile_externally(profiled_code) + if $external + $profile_externally(profiled_code) + else + $profile_internally(profiled_code; $(remaining...)) + end end end -# ITT collection control is process-wide, so an inner session pausing the collector would -# truncate an outer one. +""" + oneAPI.@bprofile [time=1.0] [trace=false] [raw=false] code... + +Benchmark the GPU execution of `code` by running it repeatedly for `time` seconds, and +report the aggregated results using the integrated profiler ([`oneAPI.@profile`](@ref)). +`code` runs once before profiling, to exclude compilation, and the task's stream is +synchronized after every iteration. + +The `time` keyword argument is optional and defaults to `1.0` seconds; the remaining +keyword arguments are forwarded to `oneAPI.@profile`. +""" +macro bprofile(ex...) + code = ex[end] + kwargs = ex[1:end-1] + + remaining = Expr[] + for kwarg in kwargs + Meta.isexpr(kwarg, :(=)) || + throw(ArgumentError("Invalid keyword argument to oneAPI.@bprofile: $kwarg")) + key, value = kwarg.args + key === :external && + throw(ArgumentError("The `external` keyword argument is not supported by oneAPI.@bprofile")) + key in (:time, :trace, :raw) || + throw(ArgumentError("Invalid keyword argument to oneAPI.@bprofile: $kwarg")) + push!(remaining, Expr(:kw, key, esc(value))) + end + + quote + profiled_code() = $(esc(code)) + $with_session() do + $(Profiling.benchmark_and_profile)(profiled_code; $(remaining...)) + end + end +end + +# Profiling state is process-wide: an inner session pausing an ITT collector, or disabling +# PTI's views, would truncate an outer one. const profiling = Threads.Atomic{Bool}(false) +function with_session(f) + Threads.atomic_cas!(profiling, false, true) && + error("oneAPI.@profile does not support nested or concurrent profiling sessions") + try + f() + finally + profiling[] = false + end +end + +profile_internally(f; kwargs...) = with_session(() -> Profiling.profile_internally(f; kwargs...)) + itt_collector() = IntelITT.ittapi_jll.is_available() && IntelITT.isactive() # A profiler that initializes Level Zero before oneAPI.jl does (e.g. unitrace, which is @@ -74,9 +164,7 @@ function check_level_zero_libraries() end function profile_externally(@nospecialize(f)) - Threads.atomic_cas!(profiling, false, true) && - error("oneAPI.@profile does not support nested or concurrent profiling sessions") - try + with_session() do stream = global_stream(context(), device()) synchronize(stream) @@ -99,7 +187,5 @@ function profile_externally(@nospecialize(f)) collector && IntelITT.pause() end end - finally - profiling[] = false end end diff --git a/src/profiling.jl b/src/profiling.jl new file mode 100644 index 000000000..a267bd82c --- /dev/null +++ b/src/profiling.jl @@ -0,0 +1,438 @@ +# Integrated profiler, built on Intel's Profiling Tools Interfaces (PTI). +# +# The display code is adapted from Metal.jl's integrated profiler. + +module Profiling + +using ..oneAPI +using ..oneAPI: PTI, global_stream + +using Printf: @sprintf +using Statistics: mean, std, quantile + +using PrettyTables: pretty_table, TextHighlighter +using Crayons: @crayon_str + + +# +# data collection +# + +const views = (PTI.PTI_VIEW_DEVICE_GPU_KERNEL, PTI.PTI_VIEW_DEVICE_GPU_MEM_COPY, + PTI.PTI_VIEW_DEVICE_GPU_MEM_FILL, PTI.PTI_VIEW_DRIVER_API) + +Base.@kwdef struct ProfileResults + # device-side operations, and the Level Zero API calls made by the host, with times in + # seconds since the start of the profile and PTI's correlation IDs linking them + device::NamedTuple + host::NamedTuple + + wall::Float64 + trace::Bool + raw::Bool +end + +function profile_internally(@nospecialize(f); trace::Bool=false, raw::Bool=false) + PTI.is_available() || + error("Integrated profiling is not supported on this platform; use `oneAPI.@profile external=true` with an external profiler instead") + + stream = global_stream(oneAPI.context(), oneAPI.device()) + synchronize(stream) + + PTI.set_callbacks() + + # discard what a failed session left behind, in PTI or in the queue of buffers + PTI.ptiFlushAllViews() + PTI.foreach_record(Returns(nothing)) + lost = PTI.lost_buffers() + + enabled = PTI.pti_view_kind[] + local t_start, t_stop, records + try + for kind in views + PTI.ptiViewEnable(kind) + push!(enabled, kind) + end + t_start = PTI.ptiViewGetTimestamp() + try + f() + finally + synchronize(stream) + end + t_stop = PTI.ptiViewGetTimestamp() + finally + # attempt all of the cleanup, so that no view is left enabled + errors = Any[] + for kind in enabled + try + PTI.ptiViewDisable(kind) + catch err + push!(errors, err) + end + end + try + PTI.ptiFlushAllViews() + records = decode_records() + catch err + push!(errors, err) + end + isempty(errors) || throw(first(errors)) + end + + if PTI.lost_buffers() > lost + @warn "The profiler could not allocate memory for its records; some activity is missing from the results" + end + + seconds(t) = relative_seconds(t, t_start) + device = (; records.device.kind, records.device.name, records.device.id, + records.device.bytes, start=seconds.(records.device.start), + stop=seconds.(records.device.stop)) + host = (; records.host.name, records.host.id, records.host.tid, records.host.unfinished, + start=seconds.(records.host.start), stop=seconds.(records.host.stop)) + return ProfileResults(; device, host, wall=seconds(t_stop), trace, raw) +end + +# Other tasks can submit work before the start of the profile, so subtract in a signed type. +# Integer arithmetic retains the precision of the timestamps. +relative_seconds(t, t_start) = (Int128(t) - Int128(t_start)) / 1e9 + +function decode_records() + device = (kind=Symbol[], name=String[], id=Int[], bytes=Union{Missing,Int}[], + start=UInt64[], stop=UInt64[]) + host = (name=String[], id=Int[], tid=Int[], start=UInt64[], stop=UInt64[], + unfinished=Bool[]) + + function push_device!(kind, r, bytes) + push!(device.kind, kind) + push!(device.name, unsafe_string(r._name)) + push!(device.id, r._correlation_id) + push!(device.bytes, bytes) + push!(device.start, r._start_timestamp) + push!(device.stop, r._end_timestamp) + end + + PTI.foreach_record() do ptr + kind = unsafe_load(ptr)._view_kind + if kind == PTI.PTI_VIEW_DEVICE_GPU_KERNEL + r = unsafe_load(convert(Ptr{PTI.pti_view_record_kernel}, ptr)) + push_device!(:kernel, r, missing) + elseif kind == PTI.PTI_VIEW_DEVICE_GPU_MEM_COPY + r = unsafe_load(convert(Ptr{PTI.pti_view_record_memory_copy}, ptr)) + push_device!(:copy, r, Int(r._bytes)) + elseif kind == PTI.PTI_VIEW_DEVICE_GPU_MEM_FILL + r = unsafe_load(convert(Ptr{PTI.pti_view_record_memory_fill}, ptr)) + push_device!(:fill, r, Int(r._bytes)) + elseif kind == PTI.PTI_VIEW_DRIVER_API + r = unsafe_load(convert(Ptr{PTI.pti_view_record_api}, ptr)) + push!(host.name, PTI.api_name(r._api_group, r._api_id)) + push!(host.id, r._correlation_id) + push!(host.tid, r._thread_id) + push!(host.start, r._start_timestamp) + push!(host.stop, r._end_timestamp) + push!(host.unfinished, r._return_code == UInt32(oneL0.RESULT_NOT_READY)) + end + end + + return (; device, host) +end + + +# +# display +# + +format_percentage(x::Number) = @sprintf("%.2f%%", x * 100) + +function format_time(ts::Number...) + t = ts[1] + range, unit = if abs(t) < 1e-6 + 1e9, "ns" + elseif abs(t) < 1e-3 + 1e6, "µs" + elseif abs(t) < 1 + 1e3, "ms" + else + 1, "s" + end + + strs = String[] + let io = IOBuffer() + Base.print(io, round(t * range, digits=2), " ", unit) + push!(strs, String(take!(io))) + end + for t in ts[2:end] + let io = IOBuffer() + Base.print(io, round(t * range, digits=2)) + push!(strs, String(take!(io))) + end + end + + length(strs) == 1 ? strs[1] : strs +end + +# time during which at least one operation was executing; operations can overlap +function busy_time(start, stop) + isempty(start) && return 0.0 + perm = sortperm(start) + total = 0.0 + cur_start = start[perm[1]] + cur_stop = stop[perm[1]] + for k in 2:length(perm) + s, e = start[perm[k]], stop[perm[k]] + if s > cur_stop + total += cur_stop - cur_start + cur_start, cur_stop = s, e + else + cur_stop = max(cur_stop, e) + end + end + total + (cur_stop - cur_start) +end + +function summarize_trace(names, times, span) + groups = Dict{String,Vector{Float64}}() + for (name, t) in zip(names, times) + push!(get!(Vector{Float64}, groups, name), t) + end + + n = length(groups) + out_name = Vector{String}(undef, n) + out_time = Vector{Float64}(undef, n) + out_calls = Vector{Int}(undef, n) + out_dist = Vector{Union{Missing,@NamedTuple{std::Float64, mean::Float64, min::Float64, max::Float64}}}(undef, n) + for (i, (name, ts)) in enumerate(groups) + out_name[i] = name + out_time[i] = sum(ts) + out_calls[i] = length(ts) + out_dist[i] = length(ts) == 1 ? missing : + (; std=std(ts), mean=mean(ts), min=minimum(ts), max=maximum(ts)) + end + out_ratio = out_time ./ span + + perm = sortperm(out_ratio; rev=true) + return (name=out_name[perm], time=out_time[perm], calls=out_calls[perm], + time_dist=out_dist[perm], time_ratio=out_ratio[perm]) +end + +function time_highlighters(df) + relevant = Float64[t for t in df.time if t !== missing && t >= 1e-8] + isempty(relevant) && return TextHighlighter[] + p75 = quantile(relevant, 0.75) + p95 = quantile(relevant, 0.95) + + atleast(v, p) = v !== missing && v >= p + hl_p95 = TextHighlighter((data, i, j) -> keys(data)[j] == :time && atleast(data[j][i], p95), + crayon"red") + hl_p75 = TextHighlighter((data, i, j) -> keys(data)[j] == :time && atleast(data[j][i], p75), + crayon"yellow") + hl_bold = TextHighlighter((data, i, j) -> keys(data)[j] == :name && atleast(data.time[i], p75), + crayon"bold") + TextHighlighter[hl_p95, hl_p75, hl_bold] +end + +const trace_column_names = Dict(:id => "ID", :start => "Start", :time => "Time", + :tid => "Thread", :size => "Size", + :throughput => "Throughput", :name => "Name") +const summary_column_names = Dict(:time_ratio => "Time (%)", :time => "Total time", + :calls => "Calls", :time_dist => "Time distribution", + :name => "Name") + +# Calls that poll for the completion of work, which oneAPI.jl and oneMKL make while +# synchronizing. Functions that wait for completion can also poll, with a zero timeout, +# so those are only hidden when the work was not done yet. +const status_queries = Set(["zeEventQueryStatus", "zeFenceQueryStatus"]) + +show_host_call(name::String, unfinished::Bool, raw::Bool) = + raw || !(unfinished || name in status_queries) + +function device_trace(device) + perm = sortperm(device.start) + time = (device.stop .- device.start)[perm] + size = device.bytes[perm] + df = (id=device.id[perm], start=device.start[perm], time, size, + throughput=[b === missing || t <= 0 ? missing : b / t for (b, t) in zip(size, time)], + name=device.name[perm]) + if all(ismissing, df.size) + df = (; df.id, df.start, df.time, df.name) + end + return df +end + +function trace_formatter(df) + return function(v, _, j) + v === missing && return "-" + col = keys(df)[j] + if col in (:start, :time) + format_time(v) + elseif col === :size + Base.format_bytes(v) + elseif col === :throughput + "$(Base.format_bytes(round(Int, v)))/s" + else + v + end + end +end + +function print_trace(io, df, crop) + header = [trace_column_names[k] for k in keys(df)] + alignment = [k === :name ? :l : :r for k in keys(df)] + pretty_table(io, df; column_labels=header, alignment, formatters=[trace_formatter(df)], + highlighters=time_highlighters(df), + fit_table_in_display_horizontally=(crop == :horizontal), + fit_table_in_display_vertically=false) +end + +function summary_formatter(df) + return function(v, _, j) + col = keys(df)[j] + if col === :time_ratio + format_percentage(v) + elseif col === :time + format_time(v) + elseif col === :time_dist + v === missing && return "" + m, s, lo, hi = format_time(v.mean, v.std, v.min, v.max) + @sprintf("%9s ± %-6s (%6s ‥ %s)", m, s, lo, hi) + else + v + end + end +end + +function print_summary(io, df, crop) + header = [summary_column_names[k] for k in keys(df)] + alignment = [k in (:name, :time_dist) ? :l : :r for k in keys(df)] + pretty_table(io, df; column_labels=header, alignment, formatters=[summary_formatter(df)], + highlighters=time_highlighters(df), + fit_table_in_display_horizontally=(crop == :horizontal), + fit_table_in_display_vertically=false) +end + +function summary_table(names, times, den) + s = summarize_trace(names, times, den) + columns = [:time_ratio, :time, :calls] + any(!ismissing, s.time_dist) && push!(columns, :time_dist) + push!(columns, :name) + NamedTuple{Tuple(columns)}(Tuple(s[c] for c in columns)) +end + +function table_crop(io) + if get(io, :is_pluto, false) || get(io, :jupyter, false) + :none + elseif io isa Base.TTY || get(io, :limit, false)::Bool + :horizontal + else + :none + end +end + +function Base.show(io::IO, r::ProfileResults) + # render into a buffer, so that the code below (which takes long to compile) does not + # need to be specialized on, and precompiled for, every kind of output stream + buf = IOContext(IOContext(IOBuffer(), io), :color => get(io, :color, false)::Bool, + :displaysize => displaysize(io)) + show_results(buf, r, table_crop(io)) + write(io, take!(buf.io)) + return +end + +function show_results(io::IOContext{IOBuffer}, r::ProfileResults, crop::Symbol) + device = r.device + shown = [show_host_call(name, unfinished, r.raw) + for (name, unfinished) in zip(r.host.name, r.host.unfinished)] + host = map(col -> col[shown], r.host) + if isempty(device.name) && isempty(host.name) + print(io, "No GPU operations or Level Zero API calls were profiled.") + return + end + + den = r.wall == 0 ? 1.0 : r.wall + println(io, "Profiled over $(format_time(r.wall)).") + + # host-side activity: the Level Zero API calls, made by oneAPI.jl and by oneMKL + if isempty(host.name) + println(io, "\nNo host-side activity was recorded.") + else + times = host.stop .- host.start + htotal = sum(times) + println(io, "\nHost-side activity: $(length(host.name)) Level Zero API calls taking $(format_time(htotal)) ", + "($(format_percentage(htotal / den)) of wall-clock)") + if r.trace + perm = sortperm(host.start) + columns = [:id, :start, :time] + length(unique(host.tid)) > 1 && push!(columns, :tid) + push!(columns, :name) + all_columns = (id=host.id[perm], start=host.start[perm], time=times[perm], + tid=host.tid[perm], name=host.name[perm]) + df = NamedTuple{Tuple(columns)}(Tuple(all_columns[c] for c in columns)) + print_trace(io, df, crop) + else + print_summary(io, summary_table(host.name, times, den), crop) + end + end + + # device-side activity: kernels, copies and fills + if isempty(device.name) + println(io, "\nNo device-side activity was recorded.") + else + busy = busy_time(device.start, device.stop) + println(io, "\nDevice-side activity: GPU was busy for $(format_time(busy)) ", + "($(format_percentage(busy / den)) of wall-clock)") + if r.trace + print_trace(io, device_trace(device), crop) + else + print_summary(io, summary_table(device.name, device.stop .- device.start, den), crop) + end + end +end + + +# +# benchmarking +# + +function benchmark_and_profile(@nospecialize(f); time::Real=1.0, kwargs...) + # warm up (compilation etc.) outside of the profiled region + f() + synchronize() + + function harness() + t0 = Base.time_ns() + while (Base.time_ns() - t0) / 1e9 < time + f() + synchronize() + end + end + + profile_internally(harness; kwargs...) +end + + +# +# precompilation +# + +using PrecompileTools: @compile_workload + +# Displaying results takes seconds to compile. Each table's columns depend on the data +# (e.g. a distribution column for repeated calls), so cover the variants that are common. +@compile_workload begin + host = (name=["zeCommandListAppendLaunchKernel", "zeEventQueryStatus", + "zeCommandListAppendLaunchKernel"], + id=[1, 0, 2], tid=[1, 1, 2], unfinished=[false, true, false], + start=[0.0, 2e-6, 4e-6], stop=[1e-6, 3e-6, 5e-6]) + device = (kind=[:kernel, :copy], name=["kernel", "copy"], id=[1, 2], + bytes=Union{Missing,Int}[missing, 64], start=[1e-6, 5e-6], stop=[2e-6, 6e-6]) + single_threaded_host = map(col -> col[1:2], host) + kernels_only = (kind=[:kernel, :kernel], name=["kernel", "kernel"], id=[1, 2], + bytes=Union{Missing,Int}[missing, missing], start=[1e-6, 5e-6], + stop=[2e-6, 6e-6]) + for (host, device) in ((host, device), (single_threaded_host, kernels_only)), + trace in (false, true) + r = ProfileResults(; device, host, wall=1e-5, trace, raw=false) + show(IOContext(IOBuffer(), :limit => true), MIME"text/plain"(), r) + end +end + +end diff --git a/test/profile.jl b/test/profile.jl index 8cb653117..c2c8e50c5 100644 --- a/test/profile.jl +++ b/test/profile.jl @@ -1,5 +1,87 @@ @testset "profile" begin +kern(a) = (a[1] += 1f0; return) + +@testset "integrated" begin + if oneAPI.PTI.is_available() + a = oneArray(zeros(Float32, 4)) + @oneapi kern(a) + synchronize() + + r = oneAPI.@profile begin + @oneapi kern(a) + fill!(a, 0f0) + copyto!(a, oneArray(ones(Float32, 4))) + end + @test r isa oneAPI.Profiling.ProfileResults + @test Array(a) == ones(Float32, 4) + + # the launch is linked to the kernel it submitted + i = findfirst(startswith("kern("), r.device.name) + @test i !== nothing + @test r.device.kind[i] == :kernel + j = findfirst(==(r.device.id[i]), r.host.id) + @test j !== nothing && r.host.name[j] == "zeCommandListAppendLaunchKernel" + @test 0 <= r.device.start[i] <= r.device.stop[i] <= r.wall + + @test any(==(:copy), r.device.kind) + @test r.device.bytes[findfirst(==(:copy), r.device.kind)] == sizeof(a) + + str = sprint(show, r) + @test occursin("Host-side activity", str) + @test occursin("Device-side activity", str) + @test occursin("kern(", str) + + # work that oneAPI.jl batches is included + if oneAPI.global_stream(context(), device()).batching && !oneL0.sync_each_submission() + r = oneAPI.@profile trace=true begin + for i in 1:3; @oneapi kern(a); end + end + @test count(startswith("kern("), r.device.name) == 3 + @test occursin("ID", sprint(show, r)) + end + + # oneMKL submits its own work + A = oneArray(rand(Float32, 64, 64)) + A * A + synchronize() + r = oneAPI.@profile A * A + @test !isempty(r.device.name) + + r = oneAPI.@bprofile time=0.1 @oneapi kern(a) + @test count(startswith("kern("), r.device.name) > 1 + + # polls for unfinished work are only shown with `raw=true` + function spin(a, n) + x = a[1] + for i in 1:n + x = x * 1.0000001f0 + 1f-7 + end + a[1] = x + return + end + @oneapi spin(a, 1) + synchronize() + r = oneAPI.@profile (@oneapi spin(a, 5_000_000); synchronize()) + @test any(r.host.unfinished) + nshown(r) = parse(Int, match(r"Host-side activity: (\d+)", sprint(show, r))[1]) + @test nshown(r) <= count(!, r.host.unfinished) + @test nshown(oneAPI.Profiling.ProfileResults(; r.device, r.host, r.wall, r.trace, raw=true)) == + length(r.host.name) + + # other tasks can submit work before the profile starts + @test oneAPI.Profiling.relative_seconds(UInt64(1_000), UInt64(3_000)) == -2e-6 + + # a failing session doesn't leave its records to the next one + @test_throws "body" oneAPI.@profile (@oneapi kern(a); error("body")) + r = oneAPI.@profile nothing + @test isempty(r.device.name) + @test occursin("No device-side activity", sprint(show, r)) + else + @test_throws "not supported on this platform" oneAPI.@profile nothing + end +end + @testset "external" begin a = oneArray(zeros(Float32, 4)) @@ -15,7 +97,6 @@ # so that launches the stream batches end up on the right side of the boundary s = oneAPI.global_stream(context(), device()) if s.batching && !oneL0.sync_each_submission() - kern(a) = (a[1] += 1f0; return) pending(s) = s.batch !== nothing || !isempty(s.submitted) for i in 1:3; @oneapi kern(a); end @test pending(s) @@ -31,6 +112,9 @@ @test_throws "nested" oneAPI.@profile external=true begin oneAPI.@profile external=true nothing end + @test_throws "nested" oneAPI.@profile external=true begin + oneAPI.@bprofile time=0.1 nothing + end @test_throws "body" oneAPI.@profile external=true error("body") @test oneAPI.@profile(external=true, 1) == 1 @@ -39,10 +123,11 @@ end @testset "macro" begin - @test_throws "integrated profiling" macroexpand(@__MODULE__, :(oneAPI.@profile 1)) - @test_throws "integrated profiling" macroexpand(@__MODULE__, :(oneAPI.@profile external=false 1)) @test_throws "literal boolean" macroexpand(@__MODULE__, :(oneAPI.@profile external=x 1)) - @test_throws "Invalid keyword" macroexpand(@__MODULE__, :(oneAPI.@profile trace=true 1)) + @test_throws "Invalid keyword" macroexpand(@__MODULE__, :(oneAPI.@profile foo=true 1)) + @test_throws "does not support other" macroexpand(@__MODULE__, :(oneAPI.@profile external=true trace=true 1)) + @test_throws "not supported by oneAPI.@bprofile" macroexpand(@__MODULE__, :(oneAPI.@bprofile external=true 1)) + @test_throws "Invalid keyword" macroexpand(@__MODULE__, :(oneAPI.@bprofile foo=true 1)) end end