add support for dumping command buffers to dot files (#404)

bashbaug · web-flow · commit c9db413b11f8 · 2025-02-03T07:49:56.000-08:00
* initial support for dumping a command buffer to a dot file

* add support for dumping command buffers to a file

* cleanup and renaming

* formatting fix

* add record tags for command buffer kernel records

* final cleanup
diff --git a/docs/controls.md b/docs/controls.md
@@ -525,6 +525,16 @@ This is the list of options that is implicitly passed to CLANG to build a non-Op
 
 This is the list of options that is implicitly passed to CLANG to build an OpenCL 2.0 SPIR-V module.  Any application-provided build options will be appended to these build options.
 
+### Controls for Dumping Command Buffers
+
+##### `OmitCommandBufferNumber` (bool)
+
+If set to a nonzero value, the Intercept Layer for OpenCL Applications will omit the command buffer number from dumped file names and hash tracking.  This can produce deterministic results even if command buffers are creatd and finalized in a non-deterministic order (say, by multiple threads).
+
+##### `DumpCommandBuffers` (bool)
+
+If set to a nonzero value, the Intercept Layer for OpenCL Applications will dump the commands and dependencies in a command buffer to a file when the command buffer is successfully finalized.  The file name will have the form "CLI\_\<Command BufferNumber\>\_\<Uniqueue Command BufferHash Code\>\_cmdbuf.dot".   The command buffer is described using the DOT graph description language.
+
 ### Controls for Dumping and Injecting Buffers and Images
 
 ##### `DumpBufferHashes` (bool)
diff --git a/intercept/CMakeLists.txt b/intercept/CMakeLists.txt
@@ -60,6 +60,7 @@ source_group(Resources FILES
 set(CLINTERCEPT_SOURCE_FILES
     src/chrometracer.h
     src/chrometracer.cpp
+    src/cmdbufrecorder.h
     src/clIntercept.def
     src/clIntercept.map
     src/cli_ext.h
diff --git a/intercept/src/cmdbufrecorder.h b/intercept/src/cmdbufrecorder.h
@@ -0,0 +1,175 @@
+/*
+// Copyright (c) 2025 Intel Corporation
+//
+// SPDX-License-Identifier: MIT
+*/
+#pragma once
+
+#include <atomic>
+#include <cinttypes>
+#include <map>
+#include <vector>
+#include <sstream>
+
+#include <stdint.h>
+
+#include "common.h"
+
+struct SCommandBufferRecord
+{
+    void    recordCreate(
+                cl_command_buffer_khr cmdbuf,
+                bool isInOrder)
+    {
+        queueIsInOrder = isInOrder;
+        dotstring << "digraph {\n";
+        dotstring << "  // " << (queueIsInOrder ? "in-order" : "out-of-order") << " command-buffer\n";
+    }
+
+    void    recordCommand(
+                cl_command_queue queue,
+                const char* cmd,
+                const std::string& tag,
+                cl_uint num_sync_points_in_wait_list,
+                const cl_sync_point_khr* sync_point_wait_list,
+                cl_sync_point_khr* sync_point)
+    {
+        SCommandBufferId id =
+            sync_point == nullptr ?
+            makeInternalId() :
+            makeSyncPointId(*sync_point);
+
+        dotstring << "  " << (id.isInternal ? "internal" : "syncpoint") << id.id
+              << " [shape=oval, label=\"" << cmd;
+        if( !tag.empty() )
+        {
+            dotstring << "( " << tag << " )";
+        }
+        dotstring << "\"]\n";
+
+        for( cl_uint s = 0; s < num_sync_points_in_wait_list; s++ )
+        {
+            dotstring << "  syncpoint" << sync_point_wait_list[s]
+                  << " -> "
+                  << (id.isInternal ? "internal" : "syncpoint") << id.id
+                  << " // explicit dependency\n";
+        }
+
+        for( const auto& dep : implicitDeps )
+        {
+            dotstring << "  " << (dep.isInternal ? "internal" : "syncpoint") << dep.id
+                  << " -> "
+                  << (id.isInternal ? "internal" : "syncpoint") << id.id
+                  << " [style=dashed] // implicit dependency\n";
+        }
+
+        if( queueIsInOrder )
+        {
+            implicitDeps.clear();
+            implicitDeps.push_back(id);
+        }
+        else
+        {
+            outstandingIds.push_back(id);
+        }
+    }
+
+    void    recordBarrier(
+                cl_command_queue queue,
+                const char* cmd,
+                cl_uint num_sync_points_in_wait_list,
+                const cl_sync_point_khr* sync_point_wait_list,
+                cl_sync_point_khr* sync_point)
+    {
+        SCommandBufferId id =
+            sync_point == nullptr ?
+            makeInternalId() :
+            makeSyncPointId(*sync_point);
+
+        dotstring << "  " << (id.isInternal ? "internal" : "syncpoint") << id.id
+            << " [shape=octagon, label=\"" << cmd << "\"]\n";
+
+        // If there is a sync point wait list, then the barrier depends on all
+        // of the commands in the sync point wait list. Otherwise, the barrier
+        // depends on all of the outstanding ids.
+        if( num_sync_points_in_wait_list > 0 )
+        {
+            for( cl_uint s = 0; s < num_sync_points_in_wait_list; s++ )
+            {
+                dotstring << "  syncpoint" << sync_point_wait_list[s]
+                    << " -> "
+                    << (id.isInternal ? "internal" : "syncpoint") << id.id
+                    << " // explicit dependency\n";
+            }
+        }
+        else
+        {
+            for( const auto& dep : outstandingIds )
+            {
+                dotstring << "  " << (dep.isInternal ? "internal" : "syncpoint") << dep.id
+                    << " -> "
+                    << (id.isInternal ? "internal" : "syncpoint") << id.id
+                    << " [style=dotted] // barrier dependency\n";
+            }
+            outstandingIds.clear();
+        }
+
+        // Add the implicit dependencies.
+        for( const auto& dep : implicitDeps )
+        {
+            dotstring << "  " << (dep.isInternal ? "internal" : "syncpoint") << dep.id
+                << " -> "
+                << (id.isInternal ? "internal" : "syncpoint") << id.id
+                << " [style=dashed] // implicit dependency\n";
+        }
+
+        // Now, the only implicit dependency that remains is this barrier.
+        implicitDeps.clear();
+        implicitDeps.push_back(id);
+    }
+
+    void recordFinalize()
+    {
+        dotstring << "}\n";
+    }
+
+    // Note: this cannot return a reference, because the underlying string is a
+    // temporary object.
+    const std::string getRecording() const
+    {
+        return dotstring.str();
+    }
+
+  private:
+    struct SCommandBufferId
+    {
+        bool        isInternal = false;
+        uint32_t    id = 0;
+    };
+
+    std::ostringstream dotstring;
+
+    std::atomic<uint32_t> nextInternalId;
+
+    bool    queueIsInOrder;
+
+    std::vector<SCommandBufferId>  implicitDeps;
+    std::vector<SCommandBufferId>  outstandingIds;
+
+    SCommandBufferId makeInternalId()
+    {
+        SCommandBufferId id;
+        id.isInternal = true;
+        id.id = nextInternalId.fetch_add(1, std::memory_order_relaxed);
+        return id;
+    }
+
+    SCommandBufferId makeSyncPointId(
+        cl_sync_point_khr sync_point)
+    {
+        SCommandBufferId id;
+        id.isInternal = false;
+        id.id = sync_point;
+        return id;
+    }
+};
diff --git a/intercept/src/controls.h b/intercept/src/controls.h
@@ -120,6 +120,10 @@ CLI_CONTROL( std::string,   SPIRVDis,                               "spirv-dis",
 CLI_CONTROL( std::string,   DefaultOptions,                         "-cc1 -x cl -cl-std=CL1.2 -D__OPENCL_C_VERSION__=120 -D__OPENCL_VERSION__=120 -emit-spirv -triple=spir", "This is the list of options that is implicitly passed to CLANG to build a non-OpenCL 2.0 SPIR-V module.  Any application-provided build options will be appended to these build options." )
 CLI_CONTROL( std::string,   OpenCL2Options,                         "-cc1 -x cl -cl-std=CL2.0 -D__OPENCL_C_VERSION__=200 -D__OPENCL_VERSION__=200 -emit-spirv -triple=spir", "This is the list of options that is implicitly passed to CLANG to build an OpenCL 2.0 SPIR-V module.  Any application-provided build options will be appended to these build options." )
 
+CLI_CONTROL_SEPARATOR( Controls for Dumping Command Buffers: )
+CLI_CONTROL( bool,          OmitCommandBufferNumber,                false, "If set to a nonzero value, the Intercept Layer for OpenCL Applications will omit the command buffer number from dumped file names and hash tracking.  This can produce deterministic results even if command buffers are creatd and finalized in a non-deterministic order (say, by multiple threads)." )
+CLI_CONTROL( bool,          DumpCommandBuffers,                     false, "If set to a nonzero value, the Intercept Layer for OpenCL Applications will dump the commands and dependencies in a command buffer to a file when the command buffer is successfully finalized.  The file name will have the form \"CLI_<Command BufferNumber>_<Uniqueue Command BufferHash Code>_cmdbuf.dot\".   The command buffer is described using the DOT graph description language." )
+
 CLI_CONTROL_SEPARATOR( Controls for Dumping and Injecting Buffers and Images: )
 CLI_CONTROL( bool,          DumpBufferHashes,                       false, "If set to a nonzero value, the Intercept Layer for OpenCL Applications will dump hashes of a buffer, SVM, or USM allocation rather than the full contents of the buffer.  This can be useful to identify which kernel enqueues generate different results without requiring a large amount of disk space." )
 CLI_CONTROL( bool,          DumpImageHashes,                        false, "If set to a nonzero value, the Intercept Layer for OpenCL Applications will dump hashes of an image rather than the full contents of the image.  This can be useful to identify which kernel enqueues generate different results without requiring a large amount of disk space." )
diff --git a/intercept/src/dispatch.cpp b/intercept/src/dispatch.cpp
@@ -10469,6 +10469,7 @@ CL_API_ENTRY cl_command_buffer_khr CL_API_CALL clCreateCommandBufferKHR(
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( errcode_ret[0] );
             ADD_OBJECT_ALLOCATION( retVal );
+            RECORD_COMMAND_BUFFER_CREATE( retVal, num_queues, queues );
             CALL_LOGGING_EXIT( errcode_ret[0], "returned %p", retVal );
 
             if( retVal != NULL )
@@ -10509,6 +10510,8 @@ CL_API_ENTRY cl_int CL_API_CALL clFinalizeCommandBufferKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_FINALIZE( retVal, command_buffer );
+            DUMP_COMMAND_BUFFER_RECORDING( retVal, command_buffer );
             CALL_LOGGING_EXIT( retVal );
 
             return retVal;
@@ -10715,6 +10718,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandBarrierWithWaitListKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_BARRIER(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -10779,6 +10788,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandCopyBufferKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -10851,6 +10866,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandCopyBufferRectKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -10915,6 +10936,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandCopyBufferToImageKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -10979,6 +11006,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandCopyImageKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -11045,6 +11078,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandCopyImageToBufferKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -11110,6 +11149,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandFillBufferKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -11173,6 +11218,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandFillImageKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -11236,6 +11287,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandSVMMemcpyKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -11301,6 +11358,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandSVMMemFillKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND( mutable_handle, command_buffer );
 
@@ -11362,6 +11425,14 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandNDRangeKernelKHR(
                 command_queue,
                 kernel,
                 argsString.c_str() );
+            GET_RECORD_TAG_COMMAND_BUFFER_KERNEL(
+                command_buffer,
+                kernel,
+                work_dim,
+                global_work_offset,
+                global_work_size,
+                local_work_size,
+                mutable_handle );
             HOST_PERFORMANCE_TIMING_START();
 
             cl_int  retVal = dispatchX.clCommandNDRangeKernelKHR(
@@ -11380,6 +11451,12 @@ CL_API_ENTRY cl_int CL_API_CALL clCommandNDRangeKernelKHR(
 
             HOST_PERFORMANCE_TIMING_END();
             CHECK_ERROR( retVal );
+            RECORD_COMMAND_BUFFER_COMMAND_WITH_TAG(
+                retVal,
+                command_buffer,
+                num_sync_points_in_wait_list,
+                sync_point_wait_list,
+                sync_point );
             CALL_LOGGING_EXIT_SYNC_POINT( retVal, sync_point );
             ADD_MUTABLE_COMMAND_NDRANGE( mutable_handle, command_buffer, work_dim );
 
diff --git a/intercept/src/intercept.cpp b/intercept/src/intercept.cpp
diff --git a/intercept/src/intercept.h b/intercept/src/intercept.h
