You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@tvm.apache.org by GitBox <gi...@apache.org> on 2021/09/14 23:03:26 UTC

[GitHub] [tvm] huajsj commented on a change in pull request #9012: [Relay] VLOG for finer grained control of hyper-detailed logging

huajsj commented on a change in pull request #9012:
URL: https://github.com/apache/tvm/pull/9012#discussion_r708710660



##########
File path: include/tvm/runtime/logging.h
##########
@@ -409,6 +413,68 @@ inline bool DebugLoggingEnabled() {
   return state == 1;
 }
 
+/*! \brief Helpers for \p VerboseLoggingEnabled. Exposed for unit testing only. */
+std::unordered_map<std::string, int> ParseTvmLogDebugSpec(const char* opt_spec);
+bool VerboseEnabledInMap(const char* filename, int level,
+                         const std::unordered_map<std::string, int>& map);
+
+/*!
+ * \brief Returns true if a VLOG statement in \p filename is enabled by the \p TVM_LOG_DEBUG

Review comment:
       the "\p" seems like not necessary. 

##########
File path: include/tvm/runtime/logging.h
##########
@@ -549,8 +644,10 @@ TVM_CHECK_FUNC(_NE, !=)
    (x) : (x))  // NOLINT(*)
 
 }  // namespace runtime
+
 // Re-export error types
 using runtime::Error;
 using runtime::InternalError;
+

Review comment:
       no need this line.

##########
File path: include/tvm/runtime/logging.h
##########
@@ -409,6 +413,68 @@ inline bool DebugLoggingEnabled() {
   return state == 1;
 }
 
+/*! \brief Helpers for \p VerboseLoggingEnabled. Exposed for unit testing only. */
+std::unordered_map<std::string, int> ParseTvmLogDebugSpec(const char* opt_spec);
+bool VerboseEnabledInMap(const char* filename, int level,

Review comment:
       here mixed used "std::string" and "char *",  recommend to use std::string to match existing global function style that used string.

##########
File path: include/tvm/runtime/logging.h
##########
@@ -395,8 +399,8 @@ class LogMessageVoidify {
 inline bool DebugLoggingEnabled() {
   static int state = 0;
   if (state == 0) {
-    if (auto var = std::getenv("TVM_LOG_DEBUG")) {
-      if (std::string(var) == "1") {
+    if (const char* var = std::getenv("TVM_LOG_DEBUG")) {
+      if (var[0] == '1') {

Review comment:
       According this logic there is no difference for TVM_LOG_DEBUG = 11 and TVM_LOG_DEBUG = 1, this seems like not make sense, could you help to give more information about why just check first digit here?

##########
File path: include/tvm/runtime/logging.h
##########
@@ -409,6 +413,68 @@ inline bool DebugLoggingEnabled() {
   return state == 1;
 }
 
+/*! \brief Helpers for \p VerboseLoggingEnabled. Exposed for unit testing only. */
+std::unordered_map<std::string, int> ParseTvmLogDebugSpec(const char* opt_spec);
+bool VerboseEnabledInMap(const char* filename, int level,
+                         const std::unordered_map<std::string, int>& map);
+
+/*!
+ * \brief Returns true if a VLOG statement in \p filename is enabled by the \p TVM_LOG_DEBUG
+ * environment variable for logging at verbosity \p level.
+ *
+ * Filenames are canonicalized to be w.r.t. the src/ dir of the TVM tree. (VLOG's should not
+ * appear under include/).
+ *
+ * To enable file \p relay/foo.cc up to level 2 and \p ir/bar.cc for level 0 only set:
+ * \code
+ * TVM_LOG_DEBUG="1;relay/foo.cc=2;ir/bar.cc=0;"
+ * \endcode
+ *
+ * To enable all files up to level 3 but disable \p ir/bar.cc set:
+ * \code
+ * TVM_LOG_DEBUG="1;*=2;ir/bar.cc=-1;"
+ * \endcode
+ */
+bool VerboseLoggingEnabled(const char* filename, int level);
+
+/*!
+ * \brief A stack of VLOG context messages.
+ *
+ * For use by \p VLOG_CONTEXT macro only.
+ */
+class VLogContext {
+ public:
+  void Push(std::stringstream* stream) { context_stack.push_back(stream); }
+  void Pop() {
+    if (!context_stack.empty()) {
+      context_stack.pop_back();
+    }
+  }
+
+  std::string str() const;
+
+ private:
+  std::vector<std::stringstream*> context_stack;

Review comment:
       context_stack_

##########
File path: src/runtime/logging.cc
##########
@@ -166,10 +167,121 @@ namespace tvm {
 namespace runtime {
 namespace detail {
 
+std::unordered_map<std::string, int> ParseTvmLogDebugSpec(const char* opt_spec) {
+  // Cache the verbosity level map.
+  std::unordered_map<std::string, int> map;
+  LOG(INFO) << "initializing VLOG map";
+  if (opt_spec == nullptr) {
+    LOG(INFO) << "VLOG disabled, no TVM_LOG_DEBUG environment variable";
+    return map;
+  }
+  std::string spec(opt_spec);
+  // Check we are enabled overall with at least one VLOG option.
+  if (spec.rfind("1;", 0) != 0) {
+    LOG(INFO) << "VLOG disabled, TVM_LOG_DEBUG does not start with '1;'";
+    return map;
+  }
+  size_t start = 2UL;
+  while (start < spec.size()) {
+    // We are looking for "name=level;" or "*=level;"
+    size_t end = start;
+    // Scan up to '='.
+    while (spec[end] != '=') {
+      ++end;
+      if (end >= spec.size()) {
+        LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, missing '='";
+        return map;
+      }
+    }
+    if (end == start) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, empty name";
+      return map;
+    }
+    std::string name(spec.substr(start, end - start));
+    // Skip '='
+    ++end;
+    if (end >= spec.size()) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, missing level";
+      return map;
+    }
+    // Scan up to ';'.
+    start = end;
+    while (spec[end] != ';') {
+      ++end;
+      if (end >= spec.size()) {
+        LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, missing ';'";
+        return map;
+      }
+    }
+    if (end == start) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, empty level";
+      return map;
+    }
+    std::string level_str(spec.substr(start, end - start));
+    // Skip ';'.
+    ++end;
+    // Parse level, default to 0 if ill-formed which we don't detect.
+    char* end_of_level = nullptr;
+    int level = static_cast<int>(strtol(level_str.c_str(), &end_of_level, 10));
+    if (end_of_level != level_str.c_str() + level_str.size()) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, invalid level";
+    }
+    LOG(INFO) << "adding VLOG entry for '" << name << "' at level " << level;
+    map.emplace(name, level);
+    start = end;
+  }
+  return map;
+}
+
+bool VerboseEnabledInMap(const char* filename, int level,
+                         const std::unordered_map<std::string, int>& map) {
+  if (filename == nullptr || level < 0) {
+    return false;
+  }
+  // Canonicalize filename.
+  std::string key(filename);
+  // TODO(mbs): Not Windows friendly.
+  size_t last_src = key.rfind("/src/", std::string::npos, 5);
+  if (last_src != std::string::npos) {
+    key = key.substr(last_src + 5);
+  }
+  // Assume disabled.
+  int limit = -1;
+  // Apply '*' wildcard if any.
+  auto itr = map.find("*");
+  if (itr != map.end()) {
+    limit = itr->second;
+  }
+  // Apply specific filename if any.
+  itr = map.find(key);
+  if (itr != map.end()) {
+    limit = itr->second;
+  }

Review comment:
       the duplicate map search seems like not efficient, why not  do "*" search only when key not found?

##########
File path: src/runtime/logging.cc
##########
@@ -166,10 +167,121 @@ namespace tvm {
 namespace runtime {
 namespace detail {
 
+std::unordered_map<std::string, int> ParseTvmLogDebugSpec(const char* opt_spec) {
+  // Cache the verbosity level map.
+  std::unordered_map<std::string, int> map;
+  LOG(INFO) << "initializing VLOG map";
+  if (opt_spec == nullptr) {
+    LOG(INFO) << "VLOG disabled, no TVM_LOG_DEBUG environment variable";
+    return map;
+  }
+  std::string spec(opt_spec);
+  // Check we are enabled overall with at least one VLOG option.
+  if (spec.rfind("1;", 0) != 0) {
+    LOG(INFO) << "VLOG disabled, TVM_LOG_DEBUG does not start with '1;'";
+    return map;
+  }
+  size_t start = 2UL;
+  while (start < spec.size()) {
+    // We are looking for "name=level;" or "*=level;"
+    size_t end = start;
+    // Scan up to '='.
+    while (spec[end] != '=') {
+      ++end;
+      if (end >= spec.size()) {
+        LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, missing '='";
+        return map;
+      }
+    }
+    if (end == start) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, empty name";
+      return map;
+    }
+    std::string name(spec.substr(start, end - start));
+    // Skip '='
+    ++end;
+    if (end >= spec.size()) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, missing level";
+      return map;
+    }
+    // Scan up to ';'.
+    start = end;
+    while (spec[end] != ';') {
+      ++end;
+      if (end >= spec.size()) {
+        LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, missing ';'";
+        return map;
+      }
+    }
+    if (end == start) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, empty level";
+      return map;
+    }
+    std::string level_str(spec.substr(start, end - start));
+    // Skip ';'.
+    ++end;
+    // Parse level, default to 0 if ill-formed which we don't detect.
+    char* end_of_level = nullptr;
+    int level = static_cast<int>(strtol(level_str.c_str(), &end_of_level, 10));
+    if (end_of_level != level_str.c_str() + level_str.size()) {
+      LOG(FATAL) << "TVM_LOG_DEBUG ill-formed, invalid level";
+    }
+    LOG(INFO) << "adding VLOG entry for '" << name << "' at level " << level;
+    map.emplace(name, level);
+    start = end;
+  }
+  return map;
+}
+
+bool VerboseEnabledInMap(const char* filename, int level,
+                         const std::unordered_map<std::string, int>& map) {
+  if (filename == nullptr || level < 0) {
+    return false;
+  }
+  // Canonicalize filename.
+  std::string key(filename);
+  // TODO(mbs): Not Windows friendly.
+  size_t last_src = key.rfind("/src/", std::string::npos, 5);
+  if (last_src != std::string::npos) {
+    key = key.substr(last_src + 5);

Review comment:
       key can be filename or the string after last "/src/", why for some file the key can be file name and other can not ? 
   
   for the file /abc/src/foo.cc and /def/src/foo.cc, the key will be same , is it intend logic?
   
   should avoid hardcode logic that use 5 directly
   ```
   const char * src = "/src/";
   size_t src_len = strlen(src);
   size_t last_src = key.rfind(src, std::string::npos, src_len);
   ....
      key = key.substr(last_src + src_len);
   ```
   




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@tvm.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org