Skip to content

Commit

Permalink
Prepend DPrint messages with device id, core coords, and RISC (#15790)
Browse files Browse the repository at this point in the history
### Ticket
#14487
  • Loading branch information
sagarwalTT authored Dec 12, 2024
1 parent 4b4fa3d commit ce20864
Show file tree
Hide file tree
Showing 8 changed files with 215 additions and 25 deletions.
15 changes: 8 additions & 7 deletions docs/source/tt-metalium/tools/kernel_print.rst
Original file line number Diff line number Diff line change
Expand Up @@ -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 <device id>:(<core x>, <core y>):<RISC>:.
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:
Expand Down Expand Up @@ -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.
3 changes: 2 additions & 1 deletion tests/tt_metal/tt_metal/debug_tools/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand Down
4 changes: 4 additions & 0 deletions tests/tt_metal/tt_metal/debug_tools/debug_tools_fixture.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -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(
Expand Down Expand Up @@ -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);
}

Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,113 @@
// SPDX-FileCopyrightText: © 2024 Tenstorrent Inc.
//
// SPDX-License-Identifier: Apache-2.0

#include <string>
#include <vector>
#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<string>& 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<string> 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<CoreCoord>& active_eth_cores = device->get_active_ethernet_cores(true);
CoreRangeSet crs(std::set<CoreRange>(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);
}
23 changes: 23 additions & 0 deletions tests/tt_metal/tt_metal/test_kernels/misc/print_simple.cpp
Original file line number Diff line number Diff line change
@@ -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
54 changes: 45 additions & 9 deletions tt_metal/impl/debug/dprint_server.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -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.
}
}
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -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.
Expand All @@ -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);
Expand Down Expand Up @@ -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)) {
Expand Down
7 changes: 7 additions & 0 deletions tt_metal/llrt/rtoptions.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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
21 changes: 13 additions & 8 deletions tt_metal/llrt/rtoptions.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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();
Expand All @@ -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
Expand Down

0 comments on commit ce20864

Please sign in to comment.