diff --git a/docs/source/tt-metalium/tools/kernel_print.rst b/docs/source/tt-metalium/tools/kernel_print.rst index 58edf78f38f..3d6844cb2f2 100644 --- a/docs/source/tt-metalium/tools/kernel_print.rst +++ b/docs/source/tt-metalium/tools/kernel_print.rst @@ -21,12 +21,13 @@ Note that the core coordinates are logical coordinates, so worker cores and ethe .. code-block:: - export TT_METAL_DPRINT_CORES=0,0 # required, x,y OR (x1,y1),(x2,y2),(x3,y3) OR (x1,y1)-(x2,y2) OR all OR worker OR dispatch - export TT_METAL_DPRINT_ETH_CORES=0,0 # optional, x,y OR (x1,y1),(x2,y2),(x3,y3) OR (x1,y1)-(x2,y2) OR all OR worker OR dispatch - export TT_METAL_DPRINT_CHIPS=0 # optional, comma separated list of chips - export TT_METAL_DPRINT_RISCVS=BR # optional, default is all RISCs. Use a subset of BR,NC,TR0,TR1,TR2 - export TT_METAL_DPRINT_FILE=log.txt # optional, default is to print to the screen - export TT_METAL_DPRINT_ONE_FILE_PER_RISC=1 # optional, splits DPRINT data on a per-RISC basis into files under $TT_METAL_HOME/generated/dprint/. Overrides TT_METAL_DPRINT_FILE. + export TT_METAL_DPRINT_CORES=0,0 # required, x,y OR (x1,y1),(x2,y2),(x3,y3) OR (x1,y1)-(x2,y2) OR all OR worker OR dispatch + export TT_METAL_DPRINT_ETH_CORES=0,0 # optional, x,y OR (x1,y1),(x2,y2),(x3,y3) OR (x1,y1)-(x2,y2) OR all OR worker OR dispatch + export TT_METAL_DPRINT_CHIPS=0 # optional, comma separated list of chips + export TT_METAL_DPRINT_RISCVS=BR # optional, default is all RISCs. Use a subset of BR,NC,TR0,TR1,TR2 + export TT_METAL_DPRINT_FILE=log.txt # optional, default is to print to the screen + export TT_METAL_DPRINT_PREPEND_DEVICE_CORE_RISC=0 # optional, enabled by default. Prepends prints with :(, )::. + export TT_METAL_DPRINT_ONE_FILE_PER_RISC=1 # optional, splits DPRINT data on a per-RISC basis into files under $TT_METAL_HOME/generated/dprint/. Overrides TT_METAL_DPRINT_FILE and disables TT_METAL_DPRINT_PREPEND_DEVICE_CORE_RISC. To generate kernel debug prints on the device, include the ``debug/dprint.h`` header and use the APIs defined there. An example with the different features available is shown below: @@ -122,4 +123,4 @@ formats for printing from CBs are ``DataFormat::Float32``, ``DataFormat::Float16 } .. note:: - Note that the DPRINT buffer for a RISC is flushed when ``ENDL()`` is called, a ``\n`` character is read, or the device that the RISC belongs to is closed. + The DPRINT buffer for a RISC is only flushed when ``ENDL()`` is called, a ``\n`` character is read, or the device that the RISC belongs to is closed. diff --git a/tests/tt_metal/tt_metal/debug_tools/CMakeLists.txt b/tests/tt_metal/tt_metal/debug_tools/CMakeLists.txt index 6cafd9ea200..76f23590016 100644 --- a/tests/tt_metal/tt_metal/debug_tools/CMakeLists.txt +++ b/tests/tt_metal/tt_metal/debug_tools/CMakeLists.txt @@ -7,6 +7,7 @@ set(UNIT_TESTS_DEBUG_TOOLS_SRC ${CMAKE_CURRENT_SOURCE_DIR}/dprint/test_print_all_harts.cpp ${CMAKE_CURRENT_SOURCE_DIR}/dprint/test_print_before_finish.cpp ${CMAKE_CURRENT_SOURCE_DIR}/dprint/test_print_hanging.cpp + ${CMAKE_CURRENT_SOURCE_DIR}/dprint/test_print_prepend_device_core_risc.cpp ${CMAKE_CURRENT_SOURCE_DIR}/dprint/test_print_tensix_dest.cpp ${CMAKE_CURRENT_SOURCE_DIR}/dprint/test_print_tiles.cpp ${CMAKE_CURRENT_SOURCE_DIR}/dprint/test_raise_wait.cpp @@ -22,7 +23,7 @@ set(UNIT_TESTS_DEBUG_TOOLS_SRC add_executable(unit_tests_debug_tools ${UNIT_TESTS_DEBUG_TOOLS_SRC}) TT_ENABLE_UNITY_BUILD(unit_tests_debug_tools) -target_link_libraries(unit_tests_debug_tools PUBLIC test_metal_common_libs) +target_link_libraries(unit_tests_debug_tools PRIVATE test_metal_common_libs) target_include_directories( unit_tests_debug_tools PRIVATE diff --git a/tests/tt_metal/tt_metal/debug_tools/debug_tools_fixture.hpp b/tests/tt_metal/tt_metal/debug_tools/debug_tools_fixture.hpp index 9d4f6714258..481bdfac670 100644 --- a/tests/tt_metal/tt_metal/debug_tools/debug_tools_fixture.hpp +++ b/tests/tt_metal/tt_metal/debug_tools/debug_tools_fixture.hpp @@ -46,6 +46,8 @@ class DPrintFixture : public DebugToolsFixture { // used by all tests using this fixture, so set dprint enabled for // all cores and all devices tt::llrt::RunTimeOptions::get_instance().set_feature_enabled(tt::llrt::RunTimeDebugFeatureDprint, true); + tt::llrt::RunTimeOptions::get_instance().set_feature_prepend_device_core_risc( + tt::llrt::RunTimeDebugFeatureDprint, false); tt::llrt::RunTimeOptions::get_instance().set_feature_all_cores( tt::llrt::RunTimeDebugFeatureDprint, CoreType::WORKER, tt::llrt::RunTimeDebugClassWorker); tt::llrt::RunTimeOptions::get_instance().set_feature_all_cores( @@ -79,6 +81,8 @@ class DPrintFixture : public DebugToolsFixture { tt::llrt::RunTimeDebugFeatureDprint, CoreType::ETH, tt::llrt::RunTimeDebugClassNoneSpecified); tt::llrt::RunTimeOptions::get_instance().set_feature_all_chips(tt::llrt::RunTimeDebugFeatureDprint, false); tt::llrt::RunTimeOptions::get_instance().set_feature_file_name(tt::llrt::RunTimeDebugFeatureDprint, ""); + tt::llrt::RunTimeOptions::get_instance().set_feature_prepend_device_core_risc( + tt::llrt::RunTimeDebugFeatureDprint, true); tt::llrt::RunTimeOptions::get_instance().set_test_mode_enabled(false); } diff --git a/tests/tt_metal/tt_metal/debug_tools/dprint/test_print_prepend_device_core_risc.cpp b/tests/tt_metal/tt_metal/debug_tools/dprint/test_print_prepend_device_core_risc.cpp new file mode 100644 index 00000000000..7d3f55f0ca5 --- /dev/null +++ b/tests/tt_metal/tt_metal/debug_tools/dprint/test_print_prepend_device_core_risc.cpp @@ -0,0 +1,113 @@ +// SPDX-FileCopyrightText: © 2024 Tenstorrent Inc. +// +// SPDX-License-Identifier: Apache-2.0 + +#include +#include +#include "core_coord.hpp" +#include "debug_tools_fixture.hpp" +#include "gtest/gtest.h" +#include "debug_tools_test_utils.hpp" +#include "kernels/kernel_types.hpp" +#include "tt_metal/detail/tt_metal.hpp" +#include "tt_metal/host_api.hpp" + +//////////////////////////////////////////////////////////////////////////////// +// A test for checking that prints are prepended with their corresponding device, core and RISC. +//////////////////////////////////////////////////////////////////////////////// +using namespace tt; +using namespace tt::tt_metal; + +namespace { +namespace CMAKE_UNIQUE_NAMESPACE { +static void UpdateGoldenOutput(std::vector& golden_output, const Device* device, const string& risc) { + // Using wildcard characters in lieu of actual values for the physical coordinates as physical coordinates can vary + // by machine + const string& device_core_risc = std::to_string(device->id()) + ":(x=*,y=*):" + risc + ": "; + + const string& output_line_all_riscs = device_core_risc + "Printing on a RISC."; + golden_output.push_back(output_line_all_riscs); + + if (risc != "ER") { + const string& output_line_risc = device_core_risc + "Printing on " + risc + "."; + golden_output.push_back(output_line_risc); + } +} + +static void RunTest(DPrintFixture* fixture, Device* device, const bool add_active_eth_kernel = false) { + std::vector golden_output; + + CoreRange cores({0, 0}, {0, 1}); + Program program = Program(); + + KernelHandle brisc_kernel_id = CreateKernel( + program, + "tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp", + cores, + DataMovementConfig{.processor = DataMovementProcessor::RISCV_0, .noc = NOC::RISCV_0_default}); + + KernelHandle ncrisc_kernel_id = CreateKernel( + program, + "tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp", + cores, + DataMovementConfig{.processor = DataMovementProcessor::RISCV_1, .noc = NOC::RISCV_1_default}); + + KernelHandle trisc_kernel_id = + CreateKernel(program, "tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp", cores, ComputeConfig{}); + + for (const CoreCoord& core : cores) { + UpdateGoldenOutput(golden_output, device, "BR"); + UpdateGoldenOutput(golden_output, device, "NC"); + UpdateGoldenOutput(golden_output, device, "TR0"); + UpdateGoldenOutput(golden_output, device, "TR1"); + UpdateGoldenOutput(golden_output, device, "TR2"); + } + + if (add_active_eth_kernel) { + const std::unordered_set& active_eth_cores = device->get_active_ethernet_cores(true); + CoreRangeSet crs(std::set(active_eth_cores.begin(), active_eth_cores.end())); + KernelHandle erisc_kernel_id = CreateKernel( + program, + "tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp", + crs, + EthernetConfig{.noc = NOC::NOC_0}); + + for (const CoreCoord& core : active_eth_cores) { + UpdateGoldenOutput(golden_output, device, "ER"); + } + } + + fixture->RunProgram(device, program); + + // Check the print log against golden output. + EXPECT_TRUE(FileContainsAllStrings(DPrintFixture::dprint_file_name, golden_output)); +} +} // namespace CMAKE_UNIQUE_NAMESPACE +} // namespace + +TEST_F(DPrintFixture, TensixTestPrintPrependDeviceCoreRisc) { + tt::llrt::RunTimeOptions::get_instance().set_feature_prepend_device_core_risc( + tt::llrt::RunTimeDebugFeatureDprint, true); + for (Device* device : this->devices_) { + this->RunTestOnDevice( + [](DPrintFixture* fixture, Device* device) { CMAKE_UNIQUE_NAMESPACE::RunTest(fixture, device); }, device); + } + tt::llrt::RunTimeOptions::get_instance().set_feature_prepend_device_core_risc( + tt::llrt::RunTimeDebugFeatureDprint, false); +} + +TEST_F(DPrintFixture, TensixActiveEthTestPrintPrependDeviceCoreRisc) { + tt::llrt::RunTimeOptions::get_instance().set_feature_prepend_device_core_risc( + tt::llrt::RunTimeDebugFeatureDprint, true); + for (Device* device : this->devices_) { + if (device->get_active_ethernet_cores(true).empty()) { + log_info(tt::LogTest, "Skipping device {} due to no active ethernet cores...", device->id()); + continue; + } + this->RunTestOnDevice( + [](DPrintFixture* fixture, Device* device) { CMAKE_UNIQUE_NAMESPACE::RunTest(fixture, device, true); }, + device); + } + tt::llrt::RunTimeOptions::get_instance().set_feature_prepend_device_core_risc( + tt::llrt::RunTimeDebugFeatureDprint, false); +} diff --git a/tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp b/tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp new file mode 100644 index 00000000000..3a55bc909cd --- /dev/null +++ b/tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp @@ -0,0 +1,23 @@ +// SPDX-FileCopyrightText: © 2024 Tenstorrent Inc. +// +// SPDX-License-Identifier: Apache-2.0 + +#include "debug/dprint.h" + +#if defined(COMPILE_FOR_TRISC) +#include "compute_kernel_api/common.h" +namespace NAMESPACE { +void MAIN { +#else +void kernel_main() { +#endif + DPRINT << "Printing on a RISC." << ENDL(); + DPRINT_UNPACK(DPRINT << "Printing on TR0." << ENDL();); + DPRINT_MATH(DPRINT << "Printing on TR1." << ENDL();); + DPRINT_PACK(DPRINT << "Printing on TR2." << ENDL();); + DPRINT_DATA0(DPRINT << "Printing on BR." << ENDL();); + DPRINT_DATA1(DPRINT << "Printing on NC." << ENDL();); +} +#if defined(COMPILE_FOR_TRISC) +} +#endif diff --git a/tt_metal/impl/debug/dprint_server.cpp b/tt_metal/impl/debug/dprint_server.cpp index d0e62e69210..8b875682fac 100644 --- a/tt_metal/impl/debug/dprint_server.cpp +++ b/tt_metal/impl/debug/dprint_server.cpp @@ -57,21 +57,21 @@ static inline float bfloat16_to_float(uint16_t bfloat_val) { return f; } -static string GetRiscName(CoreType core_type, int hart_id) { +static string GetRiscName(CoreType core_type, int hart_id, bool abbreviated = false) { if (core_type == CoreType::ETH) { switch (hart_id) { case DPRINT_RISCV_INDEX_ER: - return "ERISC"; + return abbreviated ? "ER" : "ERISC"; // Default case falls through and handled at end. } } else { switch (hart_id) { - case DPRINT_RISCV_INDEX_NC: return "NCRISC"; - case DPRINT_RISCV_INDEX_TR0: return "TRISC0"; - case DPRINT_RISCV_INDEX_TR1: return "TRISC1"; - case DPRINT_RISCV_INDEX_TR2: return "TRISC2"; + case DPRINT_RISCV_INDEX_NC: return abbreviated ? "NC" : "NCRISC"; + case DPRINT_RISCV_INDEX_TR0: return abbreviated ? "TR0" : "TRISC0"; + case DPRINT_RISCV_INDEX_TR1: return abbreviated ? "TR1" : "TRISC1"; + case DPRINT_RISCV_INDEX_TR2: return abbreviated ? "TR2" : "TRISC2"; case DPRINT_RISCV_INDEX_BR: - return "BRISC"; + return abbreviated ? "BR" : "BRISC"; // Default case falls through and handled at end. } } @@ -226,6 +226,9 @@ struct DebugPrintServerContext { // data is visible to the user. void TransferToAndFlushOutputStream(const HartKey& hart_key, ostringstream* intermediate_stream); + // Returns the dprint data that should be outputted by the output stream. + string GetDataToOutput(const HartKey& hart_key, const ostringstream* stream); + // Returns the stream that the dprint data should be output to. Can be auto-generated files, the user-selected file, // stdout, or nothing. ostream* GetOutputStream(const HartKey& hart_key); @@ -466,6 +469,8 @@ DebugPrintServerContext::DebugPrintServerContext() { tt::llrt::RunTimeOptions::get_instance().get_feature_file_name(tt::llrt::RunTimeDebugFeatureDprint); bool one_file_per_risc = tt::llrt::RunTimeOptions::get_instance().get_feature_one_file_per_risc(tt::llrt::RunTimeDebugFeatureDprint); + bool prepend_device_core_risc = + tt::llrt::RunTimeOptions::get_instance().get_feature_prepend_device_core_risc(tt::llrt::RunTimeDebugFeatureDprint); // One file per risc auto-generates the output files and ignores the env var for it. Print a warning if both are // specified just in case. @@ -475,6 +480,13 @@ DebugPrintServerContext::DebugPrintServerContext() { "TT_METAL_DPRINT_FILE_NAME will be ignored."); } + if (prepend_device_core_risc && one_file_per_risc) { + log_warning( + "Both TT_METAL_DPRINT_PREPEND_DEVICE_CORE_RISC and TT_METAL_DPRINT_ONE_FILE_PER_RISC are specified. " + "TT_METAL_DPRINT_PREPEND_DEVICE_CORE_RISC will be disabled."); + tt::llrt::RunTimeOptions::get_instance().set_feature_prepend_device_core_risc(tt::llrt::RunTimeDebugFeatureDprint, false); + } + // Set the output stream according to RTOptions, either a file name or stdout if none specified. std::filesystem::path output_dir(tt::llrt::RunTimeOptions::get_instance().get_root_dir() + logfile_path); std::filesystem::create_directories(output_dir); @@ -1190,12 +1202,36 @@ void DebugPrintServerContext::TransferIntermediateStreamsToOutputStreamAndFlush( void DebugPrintServerContext::TransferToAndFlushOutputStream( const HartKey& hart_key, ostringstream* intermediate_stream) { - const string& intermediate_stream_data = intermediate_stream->str(); + const string& output_data = GetDataToOutput(hart_key, intermediate_stream); ostream* output_stream = GetOutputStream(hart_key); - *output_stream << intermediate_stream_data << flush; + *output_stream << output_data << flush; ResetStream(intermediate_stream); } // TransferToAndFlushOutputStream +string DebugPrintServerContext::GetDataToOutput(const HartKey& hart_key, const ostringstream* stream) { + string output; + const bool prepend_device_core_risc = + tt::llrt::RunTimeOptions::get_instance().get_feature_prepend_device_core_risc(tt::llrt::RunTimeDebugFeatureDprint); + if (prepend_device_core_risc) { + const chip_id_t device_id = get<0>(hart_key); + const CoreDescriptor& core_desc = get<1>(hart_key); + const uint32_t risc_id = get<2>(hart_key); + + const string& device_id_str = to_string(device_id); + const string& core_coord_str = core_desc.coord.str(); + const string& risc_name = GetRiscName(core_desc.type, risc_id, true); + output += fmt::format("{}:{}:{}: ", device_id_str, core_coord_str, risc_name); + } + + if (stream->str().empty()) { + output = ""; + } else { + output += stream->str(); + } + + return output; +} + ostream* DebugPrintServerContext::GetOutputStream(const HartKey& hart_key) { ostream* output_stream = stream_; if (tt::llrt::RunTimeOptions::get_instance().get_feature_one_file_per_risc(tt::llrt::RunTimeDebugFeatureDprint)) { diff --git a/tt_metal/llrt/rtoptions.cpp b/tt_metal/llrt/rtoptions.cpp index 174bd2cdbce..b49316825fb 100644 --- a/tt_metal/llrt/rtoptions.cpp +++ b/tt_metal/llrt/rtoptions.cpp @@ -204,6 +204,7 @@ void RunTimeOptions::ParseFeatureEnv(RunTimeDebugFeatures feature) { ParseFeatureRiscvMask(feature, feature_env_prefix + "_RISCVS"); ParseFeatureFileName(feature, feature_env_prefix + "_FILE"); ParseFeatureOneFilePerRisc(feature, feature_env_prefix + "_ONE_FILE_PER_RISC"); + ParseFeaturePrependDeviceCoreRisc(feature, feature_env_prefix + "_PREPEND_DEVICE_CORE_RISC"); // Set feature enabled if the user asked for any feature cores feature_targets[feature].enabled = false; @@ -356,6 +357,12 @@ void RunTimeOptions::ParseFeatureOneFilePerRisc(RunTimeDebugFeatures feature, co feature_targets[feature].one_file_per_risc = (env_var_str != nullptr); } +void RunTimeOptions::ParseFeaturePrependDeviceCoreRisc(RunTimeDebugFeatures feature, const std::string &env_var) { + char *env_var_str = std::getenv(env_var.c_str()); + feature_targets[feature].prepend_device_core_risc = + (env_var_str != nullptr) ? (strcmp(env_var_str, "1") == 0) : true; +} + } // namespace llrt } // namespace tt diff --git a/tt_metal/llrt/rtoptions.hpp b/tt_metal/llrt/rtoptions.hpp index b7723f0609c..dcfb336b3b3 100644 --- a/tt_metal/llrt/rtoptions.hpp +++ b/tt_metal/llrt/rtoptions.hpp @@ -81,6 +81,7 @@ struct TargetSelection { uint32_t riscv_mask = 0; std::string file_name; // File name to write output to. bool one_file_per_risc = false; + bool prepend_device_core_risc; }; class RunTimeOptions { @@ -225,6 +226,12 @@ class RunTimeOptions { inline void set_feature_one_file_per_risc(RunTimeDebugFeatures feature, bool one_file_per_risc) { feature_targets[feature].one_file_per_risc = one_file_per_risc; } + inline bool get_feature_prepend_device_core_risc(RunTimeDebugFeatures feature) { + return feature_targets[feature].prepend_device_core_risc; + } + inline void set_feature_prepend_device_core_risc(RunTimeDebugFeatures feature, bool prepend_device_core_risc) { + feature_targets[feature].prepend_device_core_risc = prepend_device_core_risc; + } inline TargetSelection get_feature_targets(RunTimeDebugFeatures feature) { return feature_targets[feature]; } inline void set_feature_targets(RunTimeDebugFeatures feature, TargetSelection targets) { feature_targets[feature] = targets; @@ -293,11 +300,12 @@ class RunTimeOptions { private: // Helper functions to parse feature-specific environment vaiables. void ParseFeatureEnv(RunTimeDebugFeatures feature); - void ParseFeatureCoreRange(RunTimeDebugFeatures feature, const std::string& env_var, CoreType core_type); - void ParseFeatureChipIds(RunTimeDebugFeatures feature, const std::string& env_var); - void ParseFeatureRiscvMask(RunTimeDebugFeatures feature, const std::string& env_var); - void ParseFeatureFileName(RunTimeDebugFeatures feature, const std::string& env_var); - void ParseFeatureOneFilePerRisc(RunTimeDebugFeatures feature, const std::string& env_var); + void ParseFeatureCoreRange(RunTimeDebugFeatures feature, const std::string &env_var, CoreType core_type); + void ParseFeatureChipIds(RunTimeDebugFeatures feature, const std::string &env_var); + void ParseFeatureRiscvMask(RunTimeDebugFeatures feature, const std::string &env_var); + void ParseFeatureFileName(RunTimeDebugFeatures feature, const std::string &env_var); + void ParseFeatureOneFilePerRisc(RunTimeDebugFeatures feature, const std::string &env_var); + void ParseFeaturePrependDeviceCoreRisc(RunTimeDebugFeatures feature, const std::string &env_var); // Helper function to parse watcher-specific environment variables. void ParseWatcherEnv(); @@ -315,9 +323,6 @@ class RunTimeOptions { bool watcher_feature_disabled(const std::string& name) { return watcher_disabled_features.find(name) != watcher_disabled_features.end(); } - - // Helper function to generate a message string when an environment variable has not been set - std::string generate_env_var_not_set_message(const std::string& env_var) const; }; } // namespace llrt