!84 serving: add GLOG_v

From: @xu-yfei
Reviewed-by: @zhoufeng54,@linqingke
Signed-off-by: @zhoufeng54

README.md

@@ -45,10 +45,10 @@ MindSpore Serving depends on the MindSpore training and inference framework. The
 
 Use the pip command to install Serving. Perform the following steps:
 
-- Download the .whl package from the MindSpore Serving page and install it.
+- Download the .whl package from the [MindSpore Serving page](https://www.mindspore.cn/versions/en) and install it.
 
     ```python
-    pip install https://ms-release.obs.cn-north-4.myhuaweicloud.com/1.1.0/Serving/ascend/ubuntu_x86/mindspore_serving-1.1.0-cp37-cp37m-linux_x86_64.whl
+    pip install mindspore_serving-{version}-cp37-cp37m-linux_{arch}.whl
     ```
 
 - Install Serving using the source code.
@@ -72,16 +72,16 @@ Use the pip command to install Serving. Perform the following steps:
     sh build.sh -e ascend
     ```
 
-    In the preceding information, `build.sh` is the build script file in the `serving` directory, Take the x86 system as an example. After the build is complete, find the .whl installation package of MindSpore in the `serving/third_party/mindspore/build/package/` directory and install it.
+    In the preceding information, `build.sh` is the build script file in the `serving` directory. After the build is complete, find the .whl installation package of MindSpore in the `serving/third_party/mindspore/build/package/` directory and install it.
 
     ```python
-    pip install mindspore_ascend-1.1.0-cp37-cp37m-linux_x86_64.whl
+    pip install mindspore_ascend-{version}-cp37-cp37m-linux_{arch}.whl
     ```
 
     Find the .whl installation package of Serving in the `serving/build/package/` directory and install it.
 
     ```python
-    pip install mindspore_serving-1.1.0-cp37-cp37m-linux_x86_64.whl
+    pip install mindspore_serving-{version}-cp37-cp37m-linux_{arch}.whl
     ```
 
 Run the following commands to verify the installation. Import the Python module. If no error is reported, the installation is successful.

README_CN.md

@@ -45,10 +45,10 @@ MindSpore Serving依赖MindSpore训练推理框架，安装完[MindSpore](https:
 
 使用pip命令安装，安装方式如下：
 
-- 请从MindSpore Serving下载页面下载并安装whl包。
+- 请从[MindSpore Serving下载页面](https://www.mindspore.cn/versions)下载并安装whl包。
 
     ```python
-    pip install https://ms-release.obs.cn-north-4.myhuaweicloud.com/1.1.0/Serving/ascend/ubuntu_x86/mindspore_serving-1.1.0-cp37-cp37m-linux_x86_64.whl
+    pip install mindspore_serving-{version}-cp37-cp37m-linux_{arch}.whl
     ```
 
 - 源码编译安装。
@@ -72,16 +72,16 @@ MindSpore Serving依赖MindSpore训练推理框架，安装完[MindSpore](https:
     sh build.sh -e ascend
     ```
 
-    其中，`build.sh`为`serving`目录下的编译脚本文件，以x86系统为例，编译完后，在`serving/third_party/mindspore/build/package/`目录下找到MindSpore的whl安装包进行安装：
+    其中，`build.sh`为`serving`目录下的编译脚本文件，编译完后，在`serving/third_party/mindspore/build/package/`目录下找到MindSpore的whl安装包进行安装：
 
     ```python
-    pip install mindspore_ascend-1.1.0-cp37-cp37m-linux_x86_64.whl
+    pip install mindspore_ascend-{version}-cp37-cp37m-linux_{arch}.whl
     ```
 
     同时在`serving/build/package/`目录下找到Serving的whl安装包进行安装：
 
     ```python
-    pip install mindspore_serving-1.1.0-cp37-cp37m-linux_x86_64.whl
+    pip install mindspore_serving-{version}-cp37-cp37m-linux_{arch}.whl
     ```
 
 执行以下命令，验证安装结果。导入Python模块不报错即安装成功：

mindspore_serving/CMakeLists.txt

@@ -116,6 +116,8 @@ target_include_directories(_mindspore_serving PRIVATE ${pybind11_INCLUDE_DIRS})
 target_link_libraries(_mindspore_serving PRIVATE serving_common)
 set_property(TARGET _mindspore_serving PROPERTY POSITION_INDEPENDENT_CODE TRUE)
 
+target_link_options(serving_common PRIVATE -Wl,-init,mindspore_serving_log_init)
+
 # user set path
 
 if (MS_WHL_LIB_PATH)

mindspore_serving/ccsrc/common/log.cc

@@ -21,6 +21,8 @@
 namespace mindspore {
 namespace serving {
 
+int g_ms_serving_log_level = LOG_WARNING;
+
 #undef Dlog
 #define Dlog(module_id, level, format, ...)                   \
   do {                                                        \
@@ -78,7 +80,7 @@ static std::string GetProcName() {
   return app_name.substr(pos + 1);
 }
 
-static std::string GetLogLevel(ERROR_LEVEL level) {
+static std::string GetLogLevel(MsLogLevel level) {
   switch (level) {
     case LOG_DEBUG:
       return "DEBUG";
@@ -93,7 +95,7 @@ static std::string GetLogLevel(ERROR_LEVEL level) {
 }
 
 // convert MsLogLevel to corresponding glog level
-static int GetGlogLevel(ERROR_LEVEL level) {
+static int GetGlogLevel(MsLogLevel level) {
   switch (level) {
     case LOG_DEBUG:
     case LOG_INFO:
@@ -107,12 +109,269 @@ static int GetGlogLevel(ERROR_LEVEL level) {
 }
 
 void LogWriter::OutputLog(const std::ostringstream &msg) const {
-  auto submodule_name = "Serving";
+  if (log_level_ < g_ms_serving_log_level) {
+    return;
+  }
+  auto submodule_name = "SERVING";
   google::LogMessage("", 0, GetGlogLevel(log_level_)).stream()
     << "[" << GetLogLevel(log_level_) << "] " << submodule_name << "(" << getpid() << "," << GetProcName()
     << "):" << GetTime() << " "
     << "[" << file_ << ":" << line_ << "] " << func_ << "] " << msg.str() << std::endl;
 }
 
+static MsLogLevel GetGlobalLogLevel() { return static_cast<MsLogLevel>(FLAGS_v); }
+
+static std::string GetEnv(const std::string &envvar) {
+  const char *value = ::getenv(envvar.c_str());
+
+  if (value == nullptr) {
+    return std::string();
+  }
+
+  return std::string(value);
+}
+
+enum LogConfigToken {
+  INVALID,      // indicate invalid token
+  LEFT_BRACE,   // '{'
+  RIGHT_BRACE,  // '}'
+  VARIABLE,     // '[A-Za-z][A-Za-z0-9_]*'
+  NUMBER,       // [0-9]+
+  COMMA,        // ','
+  COLON,        // ':'
+  EOS,          // End Of String, '\0'
+  NUM_LOG_CFG_TOKENS
+};
+
+static const char *g_tok_names[NUM_LOG_CFG_TOKENS] = {
+  "invalid",        // indicate invalid token
+  "{",              // '{'
+  "}",              // '}'
+  "variable",       // '[A-Za-z][A-Za-z0-9_]*'
+  "number",         // [0-9]+
+  ",",              // ','
+  ":",              // ':'
+  "end-of-string",  // End Of String, '\0'
+};
+
+static inline bool IsAlpha(char ch) { return (ch >= 'A' && ch <= 'Z') || (ch >= 'a' && ch <= 'z'); }
+
+static inline bool IsDigit(char ch) { return ch >= '0' && ch <= '9'; }
+
+class LogConfigLexer {
+ public:
+  explicit LogConfigLexer(const std::string &text) : buffer_(text) {
+    cur_idx_ = 0;
+    cur_token_ = LogConfigToken::INVALID;
+  }
+  ~LogConfigLexer() = default;
+
+  // skip white space, and return the first char after white space
+  char SkipWhiteSpace() {
+    while (cur_idx_ < buffer_.size()) {
+      char ch = buffer_[cur_idx_];
+      if (ch == ' ' || ch == '\t') {
+        ++cur_idx_;
+        continue;
+      }
+      return ch;
+    }
+    return '\0';
+  }
+
+  LogConfigToken GetNext(std::string *const ptr) {
+    char ch = SkipWhiteSpace();
+    // clang-format off
+    static const std::map<char, LogConfigToken> single_char_map = {
+      {'{', LogConfigToken::LEFT_BRACE},
+      {'}', LogConfigToken::RIGHT_BRACE},
+      {',', LogConfigToken::COMMA},
+      {':', LogConfigToken::COLON},
+      {'\0', LogConfigToken::EOS},
+    };
+    // clang-format on
+
+    auto iter = single_char_map.find(ch);
+    if (iter != single_char_map.end()) {
+      if (ptr != nullptr) {
+        *ptr = std::string() + ch;
+      }
+      ++cur_idx_;
+      return iter->second;
+    } else if (IsAlpha(ch)) {
+      std::ostringstream oss;
+      do {
+        oss << ch;
+        ch = buffer_[++cur_idx_];
+      } while (cur_idx_ < buffer_.size() && (IsAlpha(ch) || IsDigit(ch) || ch == '_'));
+      if (ptr != nullptr) {
+        *ptr = std::string(oss.str());
+      }
+      return LogConfigToken::VARIABLE;
+    } else if (IsDigit(ch)) {
+      std::ostringstream oss;
+      do {
+        oss << ch;
+        ch = buffer_[++cur_idx_];
+      } while (cur_idx_ < buffer_.size() && IsDigit(ch));
+      if (ptr != nullptr) {
+        *ptr = std::string(oss.str());
+      }
+      return LogConfigToken::NUMBER;
+    }
+    return LogConfigToken::INVALID;
+  }
+
+ private:
+  std::string buffer_;
+  size_t cur_idx_;
+
+  LogConfigToken cur_token_;
+  std::string cur_text_;
+};
+
+class LogConfigParser {
+ public:
+  explicit LogConfigParser(const std::string &cfg) : lexer(cfg) {}
+  ~LogConfigParser() = default;
+
+  bool Expect(LogConfigToken expected, LogConfigToken tok) {
+    if (expected != tok) {
+      MSI_LOG_WARNING << "`, but got `" << g_tok_names[tok] << "`. The whole configuration will be ignored.";
+      return false;
+    }
+    return true;
+  }
+
+  // The text of config MS_SUBMODULE_LOG_v is in the form {submodule1:log_level1,submodule2:log_level2,...}.
+  // Valid values of log levels are: 0 - debug, 1 - info, 2 - warning, 3 - error
+  // e.g. MS_SUBMODULE_LOG_v={PARSER:0, ANALYZER:2, PIPELINE:1}
+  std::map<std::string, std::string> Parse() {
+    std::map<std::string, std::string> log_levels;
+
+    bool flag_error = false;
+    std::string text;
+    auto tok = lexer.GetNext(&text);
+    // empty string
+    if (tok == LogConfigToken::EOS) {
+      return log_levels;
+    }
+
+    if (!Expect(LogConfigToken::LEFT_BRACE, tok)) {
+      return log_levels;
+    }
+
+    do {
+      std::string key, val;
+      tok = lexer.GetNext(&key);
+      if (!Expect(LogConfigToken::VARIABLE, tok)) {
+        flag_error = true;
+        break;
+      }
+
+      tok = lexer.GetNext(&text);
+      if (!Expect(LogConfigToken::COLON, tok)) {
+        flag_error = true;
+        break;
+      }
+
+      tok = lexer.GetNext(&val);
+      if (!Expect(LogConfigToken::NUMBER, tok)) {
+        flag_error = true;
+        break;
+      }
+
+      log_levels[key] = val;
+      tok = lexer.GetNext(&text);
+    } while (tok == LogConfigToken::COMMA);
+
+    if (!flag_error && !Expect(LogConfigToken::RIGHT_BRACE, tok)) {
+      flag_error = true;
+    }
+
+    if (flag_error) {
+      log_levels.clear();
+    }
+    return log_levels;
+  }
+
+ private:
+  LogConfigLexer lexer;
+};
+
+bool ParseLogLevel(const std::string &str_level, MsLogLevel *ptr_level) {
+  if (str_level.size() == 1) {
+    int ch = str_level.c_str()[0];
+    ch = ch - '0';  // substract ASCII code of '0', which is 48
+    if (ch >= LOG_DEBUG && ch <= LOG_ERROR) {
+      if (ptr_level != nullptr) {
+        *ptr_level = static_cast<MsLogLevel>(ch);
+      }
+      return true;
+    }
+  }
+  return false;
+}
+
+void InitSubModulesLogLevel() {
+  // initialize submodule's log level using global
+  auto global_log_level = GetGlobalLogLevel();
+  g_ms_serving_log_level = global_log_level;
+
+  // set submodule's log level
+  auto submodule = GetEnv("MS_SUBMODULE_LOG_v");
+  MSI_LOG(DEBUG) << "MS_SUBMODULE_LOG_v=`" << submodule << "`";
+  LogConfigParser parser(submodule);
+  auto configs = parser.Parse();
+  for (const auto &cfg : configs) {
+    if (cfg.first == "SERVING") {
+      MsLogLevel submodule_log_level;
+      if (!ParseLogLevel(cfg.second, &submodule_log_level)) {
+        MSI_LOG(WARNING) << "Illegal log level value " << cfg.second << " for " << cfg.first << ", ignore it.";
+        continue;
+      }
+      g_ms_serving_log_level = submodule_log_level;
+    }
+  }
+}
+
 }  // namespace serving
 }  // namespace mindspore
+
+extern "C" {
+#if defined(_WIN32) || defined(_WIN64)
+__attribute__((constructor)) void common_log_init(void) {
+#else
+void common_log_init(void) {
+#endif
+  // do not use glog predefined log prefix
+  FLAGS_log_prefix = false;
+  // set default log level to WARNING
+  if (mindspore::serving::GetEnv("GLOG_v").empty()) {
+    FLAGS_v = mindspore::serving::LOG_WARNING;
+  }
+
+  // set default log file mode to 0640
+  if (mindspore::serving::GetEnv("GLOG_logfile_mode").empty()) {
+    FLAGS_logfile_mode = 0640;
+  }
+  std::string logtostderr = mindspore::serving::GetEnv("GLOG_logtostderr");
+  // default print log to screen
+  if (logtostderr.empty()) {
+    FLAGS_logtostderr = true;
+  } else if (logtostderr == "0" && mindspore::serving::GetEnv("GLOG_log_dir").empty()) {
+    FLAGS_logtostderr = true;
+    MSI_LOG(WARNING) << "`GLOG_log_dir` is not set, output log to screen.";
+  }
+  mindspore::serving::InitSubModulesLogLevel();
+}
+
+// shared lib init hook
+#if defined(_WIN32) || defined(_WIN64)
+__attribute__((constructor)) void mindspore_serving_log_init(void) {
+#else
+void mindspore_serving_log_init(void) {
+#endif
+  common_log_init();
+}
+}

mindspore_serving/ccsrc/common/log.h

@@ -37,9 +37,10 @@ static constexpr int GetRelPathPos() noexcept {
            : 0;
 }
 
-#define SERVING_FILE_NAME                                                                     \
-  (sizeof(__FILE__) > GetRelPathPos() ? static_cast<const char *>(__FILE__) + GetRelPathPos() \
-                                      : static_cast<const char *>(__FILE__))
+#define SERVING_FILE_NAME                                                        \
+  (sizeof(__FILE__) > mindspore::serving::GetRelPathPos()                        \
+     ? static_cast<const char *>(__FILE__) + mindspore::serving::GetRelPathPos() \
+     : static_cast<const char *>(__FILE__))
 
 class LogStream {
  public:
@@ -97,7 +98,7 @@ class LogStream {
   std::shared_ptr<std::stringstream> sstream_;
 };
 
-enum ERROR_LEVEL {
+enum MsLogLevel {
   LOG_DEBUG,
   LOG_INFO,
   LOG_WARNING,
@@ -107,7 +108,7 @@ enum ERROR_LEVEL {
 
 class MS_API LogWriter {
  public:
-  LogWriter(const char *file, int line, const char *func, ERROR_LEVEL log_level)
+  LogWriter(const char *file, int line, const char *func, MsLogLevel log_level)
       : file_(file), line_(line), func_(func), log_level_(log_level) {}
   ~LogWriter() = default;
 
@@ -131,23 +132,34 @@ class MS_API LogWriter {
   const char *file_;
   int line_;
   const char *func_;
-  ERROR_LEVEL log_level_;
+  MsLogLevel log_level_;
 };
 
-#define MSILOG_IF(level)                                                                                      \
+extern int g_ms_serving_log_level MS_API;
+
+#define MSILOG_IF(level, condition)                                                         \
+  static_cast<void>(0),                                                                     \
+    !(condition) ? std::string()                                                            \
+                 : mindspore::serving::LogWriter(SERVING_FILE_NAME, __LINE__, __FUNCTION__, \
+                                                 mindspore::serving::LOG_##level) < mindspore::serving::LogStream()
+
+#define MSILOG_NOIF(level)                                                                                    \
   mindspore::serving::LogWriter(SERVING_FILE_NAME, __LINE__, __FUNCTION__, mindspore::serving::LOG_##level) < \
     mindspore::serving::LogStream()
 
+#define IS_OUTPUT_ON(level) (mindspore::serving::LOG_##level) >= mindspore::serving::g_ms_serving_log_level
+
 #define MSILOG_THROW                                                                                            \
   mindspore::serving::LogWriter(SERVING_FILE_NAME, __LINE__, __FUNCTION__, mindspore::serving::LOG_EXCEPTION) ^ \
     mindspore::serving::LogStream()
 
 #define MSI_LOG(level) MSI_LOG_##level
 
-#define MSI_LOG_DEBUG MSILOG_IF(DEBUG)
-#define MSI_LOG_INFO MSILOG_IF(INFO)
-#define MSI_LOG_WARNING MSILOG_IF(WARNING)
-#define MSI_LOG_ERROR MSILOG_IF(ERROR)
+#define MSI_LOG_DEBUG MSILOG_IF(DEBUG, IS_OUTPUT_ON(DEBUG))
+#define MSI_LOG_INFO MSILOG_IF(INFO, IS_OUTPUT_ON(INFO))
+#define MSI_LOG_WARNING MSILOG_IF(WARNING, IS_OUTPUT_ON(WARNING))
+#define MSI_LOG_ERROR MSILOG_IF(ERROR, IS_OUTPUT_ON(ERROR))
+
 #define MSI_LOG_EXCEPTION MSILOG_THROW
 
 #define MSI_EXCEPTION_IF_NULL(ptr)                                   \

mindspore_serving/ccsrc/common/status.h

@@ -59,7 +59,7 @@ class Status {
   {                                                                                                          \
     auto time_end_##name = std::chrono::steady_clock::now();                                                 \
     auto time_cost = std::chrono::duration<double, std::milli>(time_end_##name - time_start_##name).count(); \
-    MSI_LOG_INFO << #name " Time Cost # " << time_cost << " ms ---------------------";                       \
+    MSI_LOG_DEBUG << #name " Time Cost # " << time_cost << " ms ---------------------";                      \
   }
 
 #define INFER_STATUS(code) mindspore::serving::Status(code) < mindspore::serving::LogStream()
@@ -67,8 +67,8 @@ class Status {
   MSI_LOG_ERROR << msg;                       \
   status = mindspore::serving::Status(type, msg)
 
-#define INFER_STATUS_LOG_ERROR(code) mindspore::serving::Status(code) = MSI_LOG_ERROR
-#define INFER_STATUS_LOG_WARNING(code) mindspore::serving::Status(code) = MSI_LOG_WARNING
+#define INFER_STATUS_LOG_ERROR(code) mindspore::serving::Status(code) = MSILOG_NOIF(ERROR)
+#define INFER_STATUS_LOG_WARNING(code) mindspore::serving::Status(code) = MSILOG_NOIF(WARNING)
 
 }  // namespace mindspore::serving
 

mindspore_serving/ccsrc/master/restful/restful_request.cc

@@ -187,7 +187,6 @@ Status RestfulRequest::RestfulReplay(const std::string &replay) {
     ERROR_INFER_STATUS(status, INVALID_INPUTS, "replay_buffer_ is nullptr");
     return status;
   }
-  MSI_LOG_INFO << "replay message: " << replay;
   evbuffer_add(replay_buffer_, replay.data(), replay.size());
   evhttp_send_reply(decompose_event_request_->event_request_, HTTP_OK, "Client", replay_buffer_);
   return status;

mindspore_serving/log.py

@@ -0,0 +1,522 @@
+# Copyright 2020 Huawei Technologies Co., Ltd
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+# ============================================================================
+"""
+log module
+"""
+import sys
+import os
+import stat
+import time
+import logging
+from logging.handlers import RotatingFileHandler
+import traceback
+import threading
+import platform
+
+if platform.system() != "Windows":
+    import fcntl
+
+__all__ = ['get_level', 'get_log_config']
+
+# The lock for setting up the logger
+_setup_logger_lock = threading.Lock()
+
+# When getting the logger, Used to check whether
+# the logger already exists
+_global_logger = None
+
+# The flag for enable console output
+_std_on = '1'
+# The flag for disable console output
+_std_off = '0'
+# Rotating max bytes, default is 50M
+_logger_def_max_bytes = '52428800'
+# Rotating backup count, default is 30
+_logger_def_backup_count = '30'
+# The default log level
+_logger_def_level = '2'
+
+# Log level name and level mapping
+_name_to_level = {
+    'ERROR': 40,
+    'WARNING': 30,
+    'INFO': 20,
+    'DEBUG': 10,
+}
+
+# GLog level and level name
+_gloglevel_to_name = {
+    '3': 'ERROR',
+    '2': 'WARNING',
+    '1': 'INFO',
+    '0': 'DEBUG',
+}
+
+# The mapping of logger configurations to glog configurations
+_confmap_dict = {'level': 'GLOG_v', 'console': 'GLOG_logtostderr', 'filepath': 'GLOG_log_dir',
+                 'maxBytes': 'logger_maxBytes', 'backupCount': 'logger_backupCount'}
+
+
+class _MultiCompatibleRotatingFileHandler(RotatingFileHandler):
+    """Inherit RotatingFileHandler for multiprocess compatibility."""
+
+    def rolling_rename(self):
+        """Rolling rename log files and set permission of Log file"""
+        for i in range(self.backupCount - 1, 0, -1):
+            sfn = self.rotation_filename("%s.%d" % (self.baseFilename, i))
+            dfn = self.rotation_filename("%s.%d" % (self.baseFilename, i + 1))
+            if os.path.exists(sfn):
+                if os.path.exists(dfn):
+                    os.remove(dfn)
+                # Modify the permission of Log file
+                os.chmod(sfn, stat.S_IREAD)
+                os.rename(sfn, dfn)
+
+    def doRollover(self):
+        """Override doRollover for multiprocess compatibility
+        and setting permission of Log file"""
+        if self.stream:
+            self.stream.close()
+            self.stream = None
+
+        # Attain an exclusive lock with bloking mode by `fcntl` module.
+        with open(self.baseFilename, 'a') as file_pointer:
+            if platform.system() != "Windows":
+                fcntl.lockf(file_pointer.fileno(), fcntl.LOCK_EX)
+
+        if self.backupCount > 0:
+            self.rolling_rename()
+
+        dfn = self.rotation_filename(self.baseFilename + ".1")
+        if os.path.exists(dfn):
+            os.remove(dfn)
+        # Modify the permission of Log file
+        os.chmod(self.baseFilename, stat.S_IREAD)
+        self.rotate(self.baseFilename, dfn)
+
+        with open(self.baseFilename, 'a'):
+            # Modify the permission of Log file
+            os.chmod(self.baseFilename, stat.S_IREAD | stat.S_IWRITE)
+
+        if not self.delay:
+            self.stream = self._open()
+
+
+class _DataFormatter(logging.Formatter):
+    """Log formatter"""
+
+    def __init__(self, sub_module, fmt=None, **kwargs):
+        """
+        Initialization of logFormatter.
+
+        Args:
+            sub_module (str): The submodule name.
+            fmt (str): Specified format pattern. Default: None.
+        """
+        super(_DataFormatter, self).__init__(fmt=fmt, **kwargs)
+        self.sub_module = sub_module.upper()
+
+    def formatTime(self, record, datefmt=None):
+        """
+        Override formatTime for uniform format %Y-%m-%d-%H:%M:%S.SSS.SSS
+
+        Args:
+            record (str): Log record.
+            datefmt (str): Date format.
+
+        Returns:
+            str, formatted timestamp.
+        """
+        created_time = self.converter(record.created)
+        if datefmt:
+            return time.strftime(datefmt, created_time)
+
+        timestamp = time.strftime('%Y-%m-%d-%H:%M:%S', created_time)
+        msecs = str(round(record.msecs * 1000))
+        # Format the time stamp
+        return f'{timestamp}.{msecs[:3]}.{msecs[3:]}'
+
+    def format(self, record):
+        """
+        Apply log format with specified pattern.
+
+        Args:
+            record (str): Format pattern.
+
+        Returns:
+            str, formatted log content according to format pattern.
+        """
+        # NOTICE: when the Installation directory of mindspore changed,
+        # ms_home_path must be changed
+        ms_install_home_path = 'mindspore'
+        idx = record.pathname.rfind(ms_install_home_path)
+        if idx >= 0:
+            # Get the relative path of the file
+            record.filepath = record.pathname[idx:]
+        else:
+            record.filepath = record.pathname
+        record.sub_module = self.sub_module
+        return super().format(record)
+
+
+def _get_logger():
+    """
+    Get logger instance.
+
+    Returns:
+        Logger, a logger.
+    """
+    if _global_logger:
+        return _global_logger
+
+    kwargs = _get_env_config()
+    _verify_config(kwargs)
+    logger = _setup_logger(_adapt_cfg(kwargs))
+    return logger
+
+
+def _adapt_cfg(kwargs):
+    """
+    Glog configurations converted to logger configurations.
+
+    Args:
+        kwargs (dict): The dictionary of log configurations.
+
+            - console (str): Whether to output log to stdout.
+            - level (str): Log level.
+            - filepath (str): The path for saving logs, if console is false, a file path must be assigned.
+            - maxBytes (str): The Maximum value of a log file for rotating, only valid if console is false.
+            - backupCount (str): The count of rotating backup log files, only valid if console is false.
+
+    Returns:
+        Dict, the input parameter dictionary.
+    """
+    kwargs['level'] = _gloglevel_to_name.get(kwargs.get('level', _logger_def_level))
+    kwargs['console'] = not kwargs.get('console') == _std_off
+    kwargs['maxBytes'] = int(kwargs.get('maxBytes', _logger_def_max_bytes))
+    kwargs['backupCount'] = int(kwargs.get('backupCount', _logger_def_backup_count))
+    return kwargs
+
+
+def info(msg, *args, **kwargs):
+    """
+    Log a message with severity 'INFO' on the MindSpore logger.
+
+    Examples:
+        >>> from mindspore_serving import log as logger
+        >>> logger.info("The arg(%s) is: %r", name, arg)
+    """
+    _get_logger().info(msg, *args, **kwargs)
+
+
+def debug(msg, *args, **kwargs):
+    """
+    Log a message with severity 'DEBUG' on the MindSpore logger.
+
+    Examples:
+        >>> from mindspore_serving import log as logger
+        >>> logger.debug("The arg(%s) is: %r", name, arg)
+    """
+    _get_logger().debug(msg, *args, **kwargs)
+
+
+def error(msg, *args, **kwargs):
+    """Log a message with severity 'ERROR' on the MindSpore logger."""
+    _get_logger().error(msg, *args, **kwargs)
+
+
+def warning(msg, *args, **kwargs):
+    """Log a message with severity 'WARNING' on the MindSpore logger."""
+    _get_logger().warning(msg, *args, **kwargs)
+
+
+def get_level():
+    """
+    Get the logger level.
+
+    Returns:
+        str, the Log level includes 3(ERROR), 2(WARNING), 1(INFO), 0(DEBUG).
+
+    Examples:
+        >>> import os
+        >>> os.environ['GLOG_v'] = '0'
+        >>> from mindspore_serving import log as logger
+        >>> logger.get_level()
+    """
+    # level and glog level mapping dictionary
+    level_to_glog_level = dict(zip(_name_to_level.values(), _gloglevel_to_name.keys()))
+
+    return level_to_glog_level.get(_get_logger().getEffectiveLevel())
+
+
+def _get_formatter():
+    """
+    Get the string of log formatter.
+
+    Returns:
+        str, the string of log formatter.
+    """
+    formatter = '[%(levelname)s] %(sub_module)s(%(process)d:' \
+                '%(thread)d,%(processName)s):%(asctime)s ' \
+                '[%(filepath)s:%(lineno)d] %(message)s'
+    return formatter
+
+
+def _get_env_config():
+    """
+    Get configurations from environment variables.
+
+    Returns:
+        Dict, the dictionary of configurations.
+    """
+    config_dict = {}
+    for key, env_value in _confmap_dict.items():
+        value = os.environ.get(env_value)
+        if value:
+            config_dict[key] = value.strip()
+    return config_dict
+
+
+def _verify_config(kwargs):
+    """
+    Verify log configurations.
+
+    Args:
+        kwargs (dict): The dictionary of log configurations.
+
+            - console (str): Whether to output log to stdout.
+            - level (str): Log level.
+            - filepath (str): The path for saving logs, if console is false, a file path must be assigned.
+            - maxBytes (str): The Maximum value of a log file for rotating, only valid if console is false.
+            - backupCount (str): The count of rotating backup log files, only valid if console is false.
+    """
+    # Check the input value of level
+    level = kwargs.get('level', None)
+    if level is not None:
+        _verify_level(level)
+
+    # Check the input value of console
+    console = kwargs.get('console', None)
+    file_path = kwargs.get('filepath', None)
+
+    if console is not None:
+        if not console.isdigit() or console not in (_std_off, _std_on):
+            raise ValueError(f'Incorrect value, The value of {_confmap_dict["console"]} must be 0 or 1,'
+                             f' Output log to console, configure to 1.')
+
+        if console == _std_off and not file_path:
+            raise ValueError(f'When {_confmap_dict["console"]} is set to 0, The directory of '
+                             f'saving log must be set, {_confmap_dict["filepath"]} cannot be empty.')
+
+        # Check the input value of filepath
+        if console == _std_off and file_path is not None:
+            file_real_path = os.path.realpath(file_path)
+            if not os.path.exists(file_real_path):
+                raise ValueError(f'The file path does not exist. '
+                                 f'{_confmap_dict["filepath"]}:{file_path}')
+
+        # Check the input value of maxBytes
+        max_bytes = kwargs.get('maxBytes', None)
+        if console == _std_off and max_bytes is not None:
+            if not max_bytes.isdigit():
+                raise ValueError(f'Incorrect value, The value of {_confmap_dict["maxBytes"]} must be positive integer. '
+                                 f'{_confmap_dict["maxBytes"]}:{max_bytes}')
+
+        # Check the input value of backupCount
+        backup_count = kwargs.get('backupCount', None)
+        if console == _std_off and backup_count is not None:
+            if not backup_count.isdigit():
+                raise ValueError(f'Incorrect value, The value of {_confmap_dict["backupCount"]} must be positive '
+                                 f'integer. {_confmap_dict["backupCount"]}:{backup_count}')
+
+
+def _verify_level(level):
+    """
+    Verify log level.
+
+    Args:
+        level (str): The log level.
+    """
+    level_name = _gloglevel_to_name.get(level, None)
+
+    # Check the value of input level
+    if level_name not in _name_to_level:
+        raise ValueError(f'Incorrect log level:{level}, Please check the log level configuration, '
+                         f'desired log level :{_gloglevel_to_name}')
+
+
+def get_log_config():
+    """
+    Get logger configurations.
+
+    Returns:
+        Dict, the dictionary of logger configurations.
+
+    Examples:
+        >>> import os
+        >>> os.environ['GLOG_v'] = '1'
+        >>> os.environ['GLOG_logtostderr'] = '0'
+        >>> os.environ['GLOG_log_dir'] = '/var/log/mindspore'
+        >>> os.environ['logger_maxBytes'] = '5242880'
+        >>> os.environ['logger_backupCount'] = '10'
+        >>> from mindspore_serving import log as logger
+        >>> logger.get_log_config()
+    """
+    logger = _get_logger()
+    handler = logger.handlers[0]
+    config_dict = {}
+    config_dict['GLOG_v'] = get_level()
+    config_dict['GLOG_logtostderr'] = _std_on
+
+    if handler.name == 'FileHandler':
+        config_dict['GLOG_logtostderr'] = _std_off
+        # Separating file path and name
+        file_path_and_name = os.path.split(handler.baseFilename)
+        config_dict['GLOG_log_dir'] = file_path_and_name[0]
+        config_dict['logger_maxBytes'] = handler.maxBytes
+        config_dict['logger_backupCount'] = handler.backupCount
+    return config_dict
+
+
+def _clear_handler(logger):
+    """Clear the handlers that has been set, avoid repeated loading"""
+    for handler in logger.handlers:
+        logger.removeHandler(handler)
+
+
+def _find_caller(stack_info=False):
+    """
+    Find the stack frame of the caller.
+
+    Override findCaller on the logger, Support for getting log record.
+    Find the stack frame of the caller so that we can note the source
+    file name, function name and line number.
+
+    Args:
+        stack_info (bool): If the value is true, print stack information to the log. Default: False.
+
+    Returns:
+        tuple, the tuple of the frame data.
+    """
+    # pylint: disable=protected-access
+    f = sys._getframe(3)
+    sinfo = None
+    # log_file is used to check caller stack frame
+    log_file = os.path.normcase(f.f_code.co_filename)
+    f = f.f_back
+    rv = "(unknown file)", 0, "(unknown function)", None
+    while f:
+        co = f.f_code
+        filename = os.path.normcase(co.co_filename)
+        if log_file == filename:
+            f = f.f_back
+            continue
+        if stack_info:
+            sinfo = _get_stack_info(f)
+        rv = (co.co_filename, f.f_lineno, co.co_name, sinfo)
+        break
+    return rv
+
+
+def _get_stack_info(frame):
+    """
+    Get the stack informations.
+
+    Args:
+        frame(frame): the frame requiring informations.
+
+    Returns:
+        str, the string of the stack informations.
+    """
+    sinfo = None
+    stack_prefix = 'Stack (most recent call last):\n'
+    sinfo = stack_prefix + "".join(traceback.format_stack(frame))
+    return sinfo
+
+
+def _setup_logger(kwargs):
+    """
+    Set up the logger.
+
+    Args:
+        kwargs (dict): The dictionary of log configurations.
+
+            - console (bool): Whether to output log to stdout. Default: True.
+            - level (str): Log level. Default: WARNING.
+            - filepath (str): The path for saving logs, if console is false, a file path must be assigned.
+            - maxBytes (int): The Maximum value of a log file for rotating, only valid if console is false.
+              Default: 52428800.
+            - backupCount (int): The count of rotating backup log files, only valid if console is false. Default: 30.
+
+    Returns:
+        Logger, well-configured logger.
+    """
+
+    # The name of Submodule
+    sub_module = 'SERVING'
+    # The name of Base log file
+    log_name = 'mindspore.log'
+
+    global _global_logger
+
+    _setup_logger_lock.acquire()
+    try:
+        if _global_logger:
+            return _global_logger
+
+        logger = logging.getLogger(name=f'{sub_module}.{log_name}')
+        # Override findCaller on the logger, Support for getting log record
+        logger.findCaller = _find_caller
+        console = kwargs.get('console', True)
+        # Set log level
+        logger.setLevel(kwargs.get('level', logging.WARNING))
+        # Set "propagate" attribute to False, stop searching up the hierarchy,
+        # avoid to load the handler of the root logger
+        logger.propagate = False
+        # Get the formatter for handler
+        formatter = _get_formatter()
+
+        # Clean up handle to avoid repeated loading
+        _clear_handler(logger)
+
+        # Set streamhandler for the console appender
+        if console:
+            console_handler = logging.StreamHandler(sys.stderr)
+            console_handler.name = 'StreamHandler'
+            console_handler.formatter = _DataFormatter(sub_module, formatter)
+            logger.addHandler(console_handler)
+
+        # Set rotatingFileHandler for the file appender
+        else:
+            # filepath cannot be null, checked in function _verify_config ()
+            logfile_dir = os.path.realpath(kwargs.get('filepath'))
+            file_name = f'{logfile_dir}/{log_name}'
+            logfile_handler = _MultiCompatibleRotatingFileHandler(
+                filename=file_name,
+                # Rotating max bytes, default is 50M
+                maxBytes=kwargs.get('maxBytes', _logger_def_max_bytes),
+                # Rotating backup count, default is 30
+                backupCount=kwargs.get('backupCount', _logger_def_backup_count),
+                encoding='utf8'
+            )
+            logfile_handler.name = 'FileHandler'
+            logfile_handler.formatter = _DataFormatter(sub_module, formatter)
+            logger.addHandler(logfile_handler)
+
+        _global_logger = logger
+
+    finally:
+        _setup_logger_lock.release()
+    return _global_logger

mindspore_serving/master/_master.py

@@ -17,6 +17,7 @@
 import threading
 from functools import wraps
 from mindspore_serving.worker import check_type
+from mindspore_serving import log as logger
 from mindspore_serving._mindspore_serving import Master_
 
 _wait_and_clear_thread = None
@@ -27,6 +28,7 @@ def _start_wait_and_clear():
     """Start thread waiting for catch ctrl+c, and clear env"""
 
     def thread_func():
+        logger.info("Serving master: wait for Ctrl+C to exit ------------------------------------")
         print("Serving master: wait for Ctrl+C to exit ------------------------------------")
         Master_.wait_and_clear()
 

mindspore_serving/worker/_check_version.py

@@ -16,6 +16,7 @@
 import os
 import sys
 from pathlib import Path
+from mindspore_serving import log as logger
 
 
 class AscendEnvChecker:
@@ -133,23 +134,23 @@ class AscendEnvChecker:
     def _check_env(self):
         """ascend dependence path check"""
         if self.path is None or self.path_check not in self.path:
-            print("Can not find ccec_compiler(need by mindspore-ascend), please check if you have set env "
-                  "PATH, you can reference to the installation guidelines https://www.mindspore.cn/install")
+            logger.warning("Can not find ccec_compiler(need by mindspore-ascend), please check if you have set env "
+                           "PATH, you can reference to the installation guidelines https://www.mindspore.cn/install")
 
         if self.python_path is None or self.python_path_check not in self.python_path:
-            print(
+            logger.warning(
                 "Can not find tbe op implement(need by mindspore-ascend), please check if you have set env "
                 "PYTHONPATH, you can reference to the installation guidelines "
                 "https://www.mindspore.cn/install")
 
         if self.ld_lib_path is None or not (self.ld_lib_path_check_fwk in self.ld_lib_path and
                                             self.ld_lib_path_check_addons in self.ld_lib_path):
-            print("Can not find driver so(need by mindspore-ascend), please check if you have set env "
-                  "LD_LIBRARY_PATH, you can reference to the installation guidelines "
-                  "https://www.mindspore.cn/install")
+            logger.warning("Can not find driver so(need by mindspore-ascend), please check if you have set env "
+                           "LD_LIBRARY_PATH, you can reference to the installation guidelines "
+                           "https://www.mindspore.cn/install")
 
         if self.ascend_opp_path is None or self.ascend_opp_path_check not in self.ascend_opp_path:
-            print(
+            logger.warning(
                 "Can not find opp path (need by mindspore-ascend), please check if you have set env ASCEND_OPP_PATH, "
                 "you can reference to the installation guidelines https://www.mindspore.cn/install")
 

mindspore_serving/worker/_worker.py

@@ -16,6 +16,7 @@
 
 import threading
 from functools import wraps
+from mindspore_serving import log as logger
 from mindspore_serving._mindspore_serving import Worker_
 from . import context
 from .task import _start_py_task
@@ -28,6 +29,7 @@ def _start_wait_and_clear():
     """Waiting for Ctrl+C, and clear up environment"""
 
     def thread_func():
+        logger.info("Serving worker: wait for Ctrl+C to exit ------------------------------------")
         print("Serving worker: wait for Ctrl+C to exit ------------------------------------")
         Worker_.wait_and_clear()
 

mindspore_serving/worker/register/method.py

@@ -22,6 +22,7 @@ from easydict import EasyDict
 from mindspore_serving._mindspore_serving import ServableStorage_, MethodSignature_, PredictPhaseTag_
 from mindspore_serving.worker.common import get_func_name, get_servable_dir
 from mindspore_serving.worker import check_type
+from mindspore_serving import log as logger
 from .preprocess import register_preprocess, check_preprocess
 from .postprocess import register_postprocess, check_postprocess
 
@@ -393,7 +394,7 @@ def _get_method_def_func_meta(method_def_func):
         if inputs_count <= 0:
             raise RuntimeError(f"Invalid '{func_name}' invoke args")
 
-        print(f"call type '{func_name}', inputs count {inputs_count}, outputs count {outputs_count}")
+        logger.info(f"call type '{func_name}', inputs count {inputs_count}, outputs count {outputs_count}")
         func_meta[func_name] = [inputs_count, outputs_count]
 
     if _call_servable_name not in func_meta:
@@ -462,8 +463,9 @@ def register_method(output_names):
                 f"Method return output size {len(output_tensors)} not match registed {len(output_names)}")
 
         method_def_context_.returns = [item.as_pair() for item in output_tensors]
-        print("------------Register method: method_name", method_def_context_.method_name,
-              ", servable_name", method_def_context_.servable_name, ", inputs", input_names, ", outputs", output_names)
+        logger.info(f"Register method: method_name {method_def_context_.method_name} "
+                    f", servable_name {method_def_context_.servable_name}, inputs: {input_names}, outputs: "
+                    f"{output_names}")
 
         global _servable_storage
         _servable_storage.register_method(method_def_context_)

mindspore_serving/worker/register/postprocess.py

@@ -16,6 +16,7 @@
 
 from mindspore_serving._mindspore_serving import PostprocessStorage_
 from mindspore_serving.worker.common import get_servable_dir, get_func_name
+from mindspore_serving import log as logger
 
 
 def check_postprocess(postprocess_name, inputs_count, outputs_count):
@@ -60,5 +61,5 @@ def register_postprocess(func, inputs_count, outputs_count):
     func_name = get_func_name(func)
     name = servable_name + "." + func_name
 
-    print("------------Register postprocess", name, inputs_count, outputs_count)
+    logger.info(f"Register postprocess {name} {inputs_count} {outputs_count}")
     postprocess_storage.register(func, name, inputs_count, outputs_count)

mindspore_serving/worker/register/preprocess.py

@@ -16,6 +16,7 @@
 
 from mindspore_serving._mindspore_serving import PreprocessStorage_
 from mindspore_serving.worker.common import get_servable_dir, get_func_name
+from mindspore_serving import log as logger
 
 
 def check_preprocess(preprocess_name, inputs_count, outputs_count):
@@ -60,5 +61,5 @@ def register_preprocess(func, inputs_count, outputs_count):
     func_name = get_func_name(func)
     name = servable_name + "." + func_name
 
-    print("------------Register preprocess", name, inputs_count, outputs_count)
+    logger.info(f"Register preprocess {name} {inputs_count} {outputs_count}")
     preprocess_storage.register(func, name, inputs_count, outputs_count)

mindspore_serving/worker/register/servable.py

@@ -17,6 +17,7 @@
 from mindspore_serving._mindspore_serving import ServableMeta_
 from mindspore_serving.worker import check_type
 from mindspore_serving.worker.common import get_servable_dir
+from mindspore_serving import log as logger
 from .method import _servable_storage
 
 
@@ -65,9 +66,9 @@ def declare_servable(servable_file, model_format, with_batch_dim=True, options=N
         meta.without_batch_dim_inputs = without_batch_dim_inputs
 
     _servable_storage.declare_servable(meta)
-    print("------------Declare servable, servable_name:", meta.servable_name,
-          ", servable_file:", servable_file, ", model_format:", model_format, ", with_batch_dim:", with_batch_dim,
-          ", options:", options, ", without_batch_dim_inputs:", without_batch_dim_inputs)
+    logger.info(f"Declare servable, servable_name: {meta.servable_name} "
+                f", servable_file: {servable_file} , model_format: {model_format},  with_batch_dim: {with_batch_dim} "
+                f", options: {options}, without_batch_dim_inputs: {without_batch_dim_inputs}")
 
 
 class AclOptions:

mindspore_serving/worker/task.py

@@ -20,6 +20,7 @@ import logging
 from mindspore_serving._mindspore_serving import Worker_
 from mindspore_serving.worker.register.preprocess import preprocess_storage
 from mindspore_serving.worker.register.postprocess import postprocess_storage
+from mindspore_serving import log as logger
 
 
 class ServingSystemException(Exception):
@@ -105,9 +106,9 @@ class PyTask:
                     self.result_batch.append(output)
 
                 get_result_time = time.time()
-                print(f"-----------------{self.task_name} get result "
-                      f"{last_index} ~ {last_index + len(self.result_batch) - 1} cost time",
-                      (get_result_time - get_result_time_end) * 1000, "ms")
+                logger.debug(f"{self.task_name} get result "
+                             f"{last_index} ~ {last_index + len(self.result_batch) - 1} cost time "
+                             f"{(get_result_time - get_result_time_end) * 1000} ms")
 
                 self.push_result_batch()
                 break
@@ -119,7 +120,7 @@ class PyTask:
             except ServingSystemException as e:
                 raise e
             except Exception as e:  # catch exception and try next
-                print("{self.task_name} get result catch exception: ")
+                logger.warning(f"{self.task_name} get result catch exception: {e}")
                 logging.exception(e)
                 self.push_failed(1)  # push success results and a failed result
                 self.temp_result = self._handle_task_continue()
@@ -149,7 +150,7 @@ class PyTask:
             outputs = self.task_info["fun"](instance_list[self.index:])
             return outputs
         except Exception as e:
-            print(f"{self.task_name} invoke catch exception: ")
+            ogger.warning(f"{self.task_name} invoke catch exception: ")
             logging.exception(e)
             self.push_failed(len(instance_list) - self.index)
             return None
@@ -217,7 +218,7 @@ class PyTaskThread(threading.Thread):
 
     def run(self):
         """Run tasks of preprocess and postprocess, switch to other type of process when some instances are handled"""
-        print("start py task for preprocess and postprocess, switch_batch", self.switch_batch)
+        logger.info(f"start py task for preprocess and postprocess, switch_batch {self.switch_batch}")
         preprocess_turn = True
         while True:
             try:
@@ -257,10 +258,10 @@ class PyTaskThread(threading.Thread):
                     preprocess_turn = True
 
             except Exception as e:
-                print("py task catch exception and exit: ")
+                logger.error(f"py task catch exception and exit: {e}")
                 logging.exception(e)
                 break
-        print("end py task for preprocess and postprocess")
+        logger.info("end py task for preprocess and postprocess")
         Worker_.stop()