diff --git a/apps/android_camera/app/src/main/jni/tvm_runtime.h b/apps/android_camera/app/src/main/jni/tvm_runtime.h index b20227b34db4..658534780130 100644 --- a/apps/android_camera/app/src/main/jni/tvm_runtime.h +++ b/apps/android_camera/app/src/main/jni/tvm_runtime.h @@ -81,12 +81,12 @@ namespace detail { // Override logging mechanism [[noreturn]] void LogFatalImpl(const std::string& file, int lineno, const std::string& message) { std::string m = file + ":" + std::to_string(lineno) + ": " + message; - __android_log_write(ANDROID_LOG_DEBUG, "TVM_RUNTIME", m.c_str()); + __android_log_write(ANDROID_LOG_FATAL, "TVM_RUNTIME", m.c_str()); throw InternalError(file, lineno, message); } -void LogMessageImpl(const std::string& file, int lineno, const std::string& message) { +void LogMessageImpl(const std::string& file, int lineno, int level, const std::string& message) { std::string m = file + ":" + std::to_string(lineno) + ": " + message; - __android_log_write(ANDROID_LOG_DEBUG, "TVM_RUNTIME", m.c_str()); + __android_log_write(ANDROID_LOG_DEBUG + level, "TVM_RUNTIME", m.c_str()); } } // namespace detail diff --git a/apps/android_rpc/app/src/main/jni/tvm_runtime.h b/apps/android_rpc/app/src/main/jni/tvm_runtime.h index 95b793a985d1..543c9c85334e 100644 --- a/apps/android_rpc/app/src/main/jni/tvm_runtime.h +++ b/apps/android_rpc/app/src/main/jni/tvm_runtime.h @@ -95,12 +95,12 @@ namespace detail { // Override logging mechanism [[noreturn]] void LogFatalImpl(const std::string& file, int lineno, const std::string& message) { std::string m = file + ":" + std::to_string(lineno) + ": " + message; - __android_log_write(ANDROID_LOG_DEBUG, "TVM_RUNTIME", m.c_str()); + __android_log_write(ANDROID_LOG_FATAL, "TVM_RUNTIME", m.c_str()); throw InternalError(file, lineno, message); } -void LogMessageImpl(const std::string& file, int lineno, const std::string& message) { +void LogMessageImpl(const std::string& file, int lineno, int level, const std::string& message) { std::string m = file + ":" + std::to_string(lineno) + ": " + message; - __android_log_write(ANDROID_LOG_DEBUG, "TVM_RUNTIME", m.c_str()); + __android_log_write(ANDROID_LOG_DEBUG + level, "TVM_RUNTIME", m.c_str()); } } // namespace detail diff --git a/apps/ios_rpc/tvmrpc/TVMRuntime.mm b/apps/ios_rpc/tvmrpc/TVMRuntime.mm index 3225b850befe..baf5c8867a92 100644 --- a/apps/ios_rpc/tvmrpc/TVMRuntime.mm +++ b/apps/ios_rpc/tvmrpc/TVMRuntime.mm @@ -45,7 +45,7 @@ throw tvm::runtime::InternalError(file, lineno, message); } -void LogMessageImpl(const std::string& file, int lineno, const std::string& message) { +void LogMessageImpl(const std::string& file, int lineno, int level, const std::string& message) { NSLog(@"%s:%d: %s", file.c_str(), lineno, message.c_str()); } diff --git a/include/tvm/runtime/logging.h b/include/tvm/runtime/logging.h index 7dbc6d810dc0..2128fc485ba4 100644 --- a/include/tvm/runtime/logging.h +++ b/include/tvm/runtime/logging.h @@ -294,7 +294,8 @@ namespace detail { * * \sa TVM_LOG_CUSTOMIZE */ -TVM_DLL void LogMessageImpl(const std::string& file, int lineno, const std::string& message); +TVM_DLL void LogMessageImpl(const std::string& file, int lineno, int level, + const std::string& message); /*! * \brief Class to accumulate an error message and throw it. Do not use @@ -325,13 +326,15 @@ class LogFatal { */ class LogMessage { public: - LogMessage(const std::string& file, int lineno) : file_(file), lineno_(lineno) {} - ~LogMessage() { LogMessageImpl(file_, lineno_, stream_.str()); } + LogMessage(const std::string& file, int lineno, int level) + : file_(file), lineno_(lineno), level_(level) {} + ~LogMessage() { LogMessageImpl(file_, lineno_, level_, stream_.str()); } std::ostringstream& stream() { return stream_; } private: std::string file_; int lineno_; + int level_; std::ostringstream stream_; }; @@ -378,17 +381,19 @@ class LogFatal { */ class LogMessage { public: - LogMessage(const std::string& file, int lineno) { + LogMessage(const std::string& file, int lineno, int level) { std::time_t t = std::time(nullptr); stream_ << "[" << std::put_time(std::localtime(&t), "%H:%M:%S") << "] " << file << ":" << lineno - << ": "; + << level_strings_[level]; } TVM_NO_INLINE ~LogMessage() { std::cerr << stream_.str() << std::endl; } std::ostringstream& stream() { return stream_; } private: std::ostringstream stream_; + TVM_DLL static const char* level_strings_[]; }; + #endif // Below is from dmlc-core @@ -568,11 +573,20 @@ TVM_CHECK_FUNC(_NE, !=) } // namespace detail +#define TVM_LOG_LEVEL_DEBUG 0 +#define TVM_LOG_LEVEL_INFO 1 +#define TVM_LOG_LEVEL_WARNING 2 +#define TVM_LOG_LEVEL_ERROR 3 +#define TVM_LOG_LEVEL_FATAL 4 #define LOG(level) LOG_##level +#define LOG_DEBUG \ + ::tvm::runtime::detail::LogMessage(__FILE__, __LINE__, TVM_LOG_LEVEL_DEBUG).stream() #define LOG_FATAL ::tvm::runtime::detail::LogFatal(__FILE__, __LINE__).stream() -#define LOG_INFO ::tvm::runtime::detail::LogMessage(__FILE__, __LINE__).stream() -#define LOG_ERROR (::tvm::runtime::detail::LogMessage(__FILE__, __LINE__).stream() << "Error: ") -#define LOG_WARNING (::tvm::runtime::detail::LogMessage(__FILE__, __LINE__).stream() << "Warning: ") +#define LOG_INFO ::tvm::runtime::detail::LogMessage(__FILE__, __LINE__, TVM_LOG_LEVEL_INFO).stream() +#define LOG_ERROR \ + ::tvm::runtime::detail::LogMessage(__FILE__, __LINE__, TVM_LOG_LEVEL_ERROR).stream() +#define LOG_WARNING \ + ::tvm::runtime::detail::LogMessage(__FILE__, __LINE__, TVM_LOG_LEVEL_WARNING).stream() #define TVM_CHECK_BINARY_OP(name, op, x, y) \ if (auto __tvm__log__err = ::tvm::runtime::detail::LogCheck##name(x, y)) \ diff --git a/python/tvm/contrib/hexagon/build.py b/python/tvm/contrib/hexagon/build.py index bc3b065dd941..e67009829771 100644 --- a/python/tvm/contrib/hexagon/build.py +++ b/python/tvm/contrib/hexagon/build.py @@ -19,6 +19,7 @@ import abc import datetime +import logging import multiprocessing as mp import os import pathlib @@ -269,6 +270,7 @@ def __init__( hexagon_debug: bool = False, clear_logcat: bool = False, sysmon_profile: bool = False, + farf_config: str = "0x1e", ): """Configure a new HexagonLauncherAndroid @@ -288,6 +290,10 @@ def __init__( Should the server clear logcat before running. sysmon_profile: bool, optional Should the server run sysmon profiler in the background. + farf_config: str, optional + Configuration string for runtime log level filtering. + Use farf_config_from_python_log_level to generate a bitmask + string from a Python logging level (e.g., logging.INFO) """ if not rpc_info.get("workspace_base"): rpc_info["workspace_base"] = self.ANDROID_HEXAGON_TEST_BASE_DIR @@ -301,6 +307,7 @@ def __init__( self._clear_logcat = clear_logcat self._sysmon_profile = sysmon_profile self._sysmon_process = None + self._farf_config = farf_config rpc_info["device_key"] = HEXAGON_REMOTE_DEVICE_KEY + "." + self._serial_number super(HexagonLauncherAndroid, self).__init__(rpc_info, workspace, self._serial_number) @@ -342,6 +349,8 @@ def _copy_binaries(self): line = line.replace( "", str(self._rpc_info["rpc_server_port"]) ) + if "" in line: + line = line.replace("", str(self._farf_config)) dest_f.write(line) # Make shell script executable @@ -710,6 +719,44 @@ def _is_port_in_use(port: int) -> bool: return s.connect_ex(("localhost", port)) == 0 +def farf_config_from_python_log_level(level) -> str: + """Generates a FARF configuration string enabling logging at the specified level + + Parameters + ---------- + level : str or int + Minimum level to log at. Must be a known Python logging level or string + (e.g., logging.INFO or "INFO") + """ + + # Runtime log levels can be selectively enabled by computing a bitmask + # corresponding to the levels you want to enable. These get forwarded to + # logcat by the DSP RPC daemon. The bits for each level are: + + # 0x01 - Hexagon LOW / TVM DEBUG / Python DEBUG + # 0x02 - Hexagon MEDIUM / TVM INFO / Python INFO + # 0x04 - Hexagon HIGH / TVM WARN / Python WARNING + # 0x08 - Hexagon ERROR / TVM ERROR / Python ERROR + # 0x10 - Hexagon FATAL / TVM FATAL / Python CRITICAL + + # Runtime logging can also be filtered on filenames by appending a + # comma-separated list of filenames. For more information, see + # the Hexagon SDK documentation. + + if level in (logging.DEBUG, "DEBUG"): + return "0x1F" + if level in (logging.INFO, "INFO"): + return "0x1E" + if level in (logging.WARNING, "WARNING"): + return "0x1C" + if level in (logging.ERROR, "ERROR"): + return "0x18" + if level in (logging.CRITICAL, "CRITICAL"): + return "0x10" + + raise ValueError("Argument must be a known Python logging level or string") + + # pylint: disable=invalid-name def HexagonLauncher( serial_number: str, @@ -718,10 +765,11 @@ def HexagonLauncher( hexagon_debug: bool = False, clear_logcat: bool = False, sysmon_profile: bool = False, + farf_config: str = farf_config_from_python_log_level(logging.INFO), ): """Creates a HexagonLauncher""" if serial_number == HEXAGON_SIMULATOR_NAME: return HexagonLauncherSimulator(rpc_info, workspace) return HexagonLauncherAndroid( - serial_number, rpc_info, workspace, hexagon_debug, clear_logcat, sysmon_profile + serial_number, rpc_info, workspace, hexagon_debug, clear_logcat, sysmon_profile, farf_config ) diff --git a/src/meta_schedule/utils.h b/src/meta_schedule/utils.h index 824cfcd6aa5c..6766df3d692e 100644 --- a/src/meta_schedule/utils.h +++ b/src/meta_schedule/utils.h @@ -92,13 +92,17 @@ class PyLogMessage { logger_(static_cast(logging_level_), std::string(filename_), lineno_, stream_.str()); } else { if (logging_level_ == Level::INFO) { - runtime::detail::LogMessage(filename_, lineno_).stream() << stream_.str(); + runtime::detail::LogMessage(filename_, lineno_, TVM_LOG_LEVEL_INFO).stream() + << stream_.str(); } else if (logging_level_ == Level::WARNING) { - runtime::detail::LogMessage(filename_, lineno_).stream() << "Warning: " << stream_.str(); + runtime::detail::LogMessage(filename_, lineno_, TVM_LOG_LEVEL_WARNING).stream() + << stream_.str(); } else if (logging_level_ == Level::ERROR) { - runtime::detail::LogMessage(filename_, lineno_).stream() << "Error: " << stream_.str(); + runtime::detail::LogMessage(filename_, lineno_, TVM_LOG_LEVEL_ERROR).stream() + << stream_.str(); } else if (logging_level_ == Level::DEBUG) { - runtime::detail::LogMessage(filename_, lineno_).stream() << "Debug: " << stream_.str(); + runtime::detail::LogMessage(filename_, lineno_, TVM_LOG_LEVEL_DEBUG).stream() + << stream_.str(); } else { runtime::detail::LogFatal(filename_, lineno_).stream() << stream_.str(); } @@ -150,7 +154,8 @@ inline void clear_logging(const char* file, int lineno, PackedFunc logging_func) logging_func(static_cast(PyLogMessage::Level::CLEAR), file, lineno, ""); } else { // this would clear all logging output in the console - runtime::detail::LogMessage(file, lineno).stream() << "\033c\033[3J\033[2J\033[0m\033[H"; + runtime::detail::LogMessage(file, lineno, TVM_LOG_LEVEL_INFO).stream() + << "\033c\033[3J\033[2J\033[0m\033[H"; } } diff --git a/src/runtime/hexagon/hexagon_common.cc b/src/runtime/hexagon/hexagon_common.cc index ec65dffebe51..79acbf8b99e2 100644 --- a/src/runtime/hexagon/hexagon_common.cc +++ b/src/runtime/hexagon/hexagon_common.cc @@ -32,6 +32,7 @@ #include #include "../library_module.h" +#include "HAP_debug.h" #include "HAP_perf.h" #include "hexagon_buffer.h" @@ -69,22 +70,22 @@ std::vector SplitString(const std::string& str, char delim) { } return lines; } -void HexagonLog(const std::string& file, int lineno, const std::string& message) { - HEXAGON_PRINT(ALWAYS, "INFO: %s:%d:", file.c_str(), lineno); +void HexagonLog(const std::string& file, int lineno, int level, const std::string& message) { std::vector err_lines = SplitString(message, '\n'); for (auto& line : err_lines) { - HEXAGON_PRINT(ALWAYS, "INFO: %s", line.c_str()); + // TVM log levels roughly map to HAP log levels + HAP_debug_runtime(level, file.c_str(), lineno, line.c_str()); } } } // namespace namespace detail { [[noreturn]] void LogFatalImpl(const std::string& file, int lineno, const std::string& message) { - HexagonLog(file, lineno, message); + HexagonLog(file, lineno, TVM_LOG_LEVEL_FATAL, message); throw InternalError(file, lineno, message); } -void LogMessageImpl(const std::string& file, int lineno, const std::string& message) { - HexagonLog(file, lineno, message); +void LogMessageImpl(const std::string& file, int lineno, int level, const std::string& message) { + HexagonLog(file, lineno, level, message); } } // namespace detail diff --git a/src/runtime/hexagon/rpc/android_bash.sh.template b/src/runtime/hexagon/rpc/android_bash.sh.template index d9f7613b0fc0..c45b03818fd3 100644 --- a/src/runtime/hexagon/rpc/android_bash.sh.template +++ b/src/runtime/hexagon/rpc/android_bash.sh.template @@ -20,7 +20,8 @@ export LD_LIBRARY_PATH=. # Enable FARF-based logging for Hexagon code invoked by 'tvm_rpc_android_server'. export ADSP_LIBRARY_PATH=`pwd` -echo 0x1f > tvm_rpc_android.farf + +echo > tvm_rpc_android.farf ./tvm_rpc_android server --port= --tracker=: --key= >${PWD}/tvm_rpc_android.log 2>&1 & diff --git a/src/runtime/hexagon/rpc/hexagon/rpc_server.cc b/src/runtime/hexagon/rpc/hexagon/rpc_server.cc index f39944615bfd..8daeeff66284 100644 --- a/src/runtime/hexagon/rpc/hexagon/rpc_server.cc +++ b/src/runtime/hexagon/rpc/hexagon/rpc_server.cc @@ -64,7 +64,7 @@ class HexagonIOHandler { void MessageStart(size_t message_size_bytes) {} ssize_t PosixWrite(const uint8_t* buf, size_t write_len_bytes) { - LOG(INFO) << "HexagonIOHandler PosixWrite called, write_len_bytes(" << write_len_bytes << ")"; + LOG(DEBUG) << "HexagonIOHandler PosixWrite called, write_len_bytes(" << write_len_bytes << ")"; int32_t written_size = write_buffer_.sputn(reinterpret_cast(buf), write_len_bytes); if (written_size != write_len_bytes) { LOG(ERROR) << "written_size(" << written_size << ") != write_len_bytes(" << write_len_bytes @@ -74,11 +74,11 @@ class HexagonIOHandler { return (ssize_t)written_size; } - void MessageDone() { LOG(INFO) << "Message Done."; } + void MessageDone() { LOG(DEBUG) << "Message Done."; } ssize_t PosixRead(uint8_t* buf, size_t read_len_bytes) { - LOG(INFO) << "HexagonIOHandler PosixRead called, read_len_bytes(" << read_len_bytes - << "), read_buffer_index_(" << read_buffer_index_ << ")"; + LOG(DEBUG) << "HexagonIOHandler PosixRead called, read_len_bytes(" << read_len_bytes + << "), read_buffer_index_(" << read_buffer_index_ << ")"; uint32_t bytes_to_read = 0; if (read_buffer_index_ < read_len_bytes) { @@ -101,9 +101,9 @@ class HexagonIOHandler { * \return The status */ AEEResult SetReadBuffer(const uint8_t* data, size_t data_size_bytes) { - LOG(INFO) << "HexagonIOHandler SetReadBuffer: data_size_bytes(" << data_size_bytes - << "), read_buffer_index_(" << read_buffer_index_ << "), read_buffer_size_bytes_(" - << read_buffer_size_bytes_ << ")"; + LOG(DEBUG) << "HexagonIOHandler SetReadBuffer: data_size_bytes(" << data_size_bytes + << "), read_buffer_index_(" << read_buffer_index_ << "), read_buffer_size_bytes_(" + << read_buffer_size_bytes_ << ")"; if (data_size_bytes > read_buffer_size_bytes_) { LOG(ERROR) << "ERROR: data_size_bytes(" << data_size_bytes << ") > read_buffer_size_bytes_(" << read_buffer_size_bytes_ << ")"; @@ -123,8 +123,8 @@ class HexagonIOHandler { * \return The size of data that is read in bytes. */ int64_t ReadFromWriteBuffer(uint8_t* buf, size_t read_size_bytes) { - LOG(INFO) << "HexagonIOHandler ReadFromWriteBuffer called, read_size_bytes: " - << read_size_bytes; + LOG(DEBUG) << "HexagonIOHandler ReadFromWriteBuffer called, read_size_bytes: " + << read_size_bytes; int64_t size = (int64_t)write_buffer_.sgetn(reinterpret_cast(buf), read_size_bytes); write_buffer_available_length_ -= size; @@ -135,7 +135,7 @@ class HexagonIOHandler { return size; } - void Close() { LOG(INFO) << "HexagonIOHandler Close called"; } + void Close() { LOG(DEBUG) << "HexagonIOHandler Close called"; } void Exit(int code) { exit(code); } @@ -264,7 +264,7 @@ int __QAIC_HEADER(hexagon_rpc_open)(const char* uri, remote_handle64* handle) { } int __QAIC_HEADER(hexagon_rpc_close)(remote_handle64 handle) { - LOG(INFO) << __func__; + LOG(DEBUG) << __func__; if (handle) { free(reinterpret_cast(static_cast(handle))); } diff --git a/src/runtime/logging.cc b/src/runtime/logging.cc index d62051f7cee0..d0ce77c931db 100644 --- a/src/runtime/logging.cc +++ b/src/runtime/logging.cc @@ -212,6 +212,13 @@ namespace tvm { namespace runtime { namespace detail { +const char* ::tvm::runtime::detail::LogMessage::level_strings_[] = { + ": Debug: ", // TVM_LOG_LEVEL_DEBUG + ": ", // TVM_LOG_LEVEL_INFO + ": Warning: ", // TVM_LOG_LEVEL_WARNING + ": Error: ", // TVM_LOG_LEVEL_ERROR +}; + namespace { constexpr const char* kSrcPrefix = "/src/"; // Note: Better would be std::char_traits::length(kSrcPrefix) but it is not diff --git a/web/emcc/wasm_runtime.cc b/web/emcc/wasm_runtime.cc index addc3a3e0c11..2b0ee49d7edd 100644 --- a/web/emcc/wasm_runtime.cc +++ b/web/emcc/wasm_runtime.cc @@ -73,8 +73,14 @@ namespace detail { abort(); } -void LogMessageImpl(const std::string& file, int lineno, const std::string& message) { - std::cout << "[INFO] " << file << ":" << lineno << ": " << message << std::endl; +void LogMessageImpl(const std::string& file, int lineno, int level, const std::string& message) { + static const char* level_strings_[] = { + "[DEBUG] ", + "[INFO] ", + "[WARNING] ", + "[ERROR] ", + }; + std::cout << level_strings_[level] << file << ":" << lineno << ": " << message << std::endl; } } // namespace detail