diff --git a/component/ascend-common/common-utils/hwlog/hwlog_adaptor.go b/component/ascend-common/common-utils/hwlog/hwlog_adaptor.go index f91a4be0fa9b453e99e43590a26444ff1b0e5a21..04785f4df90401ea900e0231c9227d5dc8e533f6 100644 --- a/component/ascend-common/common-utils/hwlog/hwlog_adaptor.go +++ b/component/ascend-common/common-utils/hwlog/hwlog_adaptor.go @@ -18,29 +18,52 @@ package hwlog import ( "context" "errors" + "fmt" ) // RunLog run logger var RunLog *logger +var ModuleRunLog = make(map[string]*logger) // InitRunLogger initialize run logger -func InitRunLogger(config *LogConfig, ctx context.Context) error { +func InitRunLogger(config *LogConfig, moduleName string, ctx context.Context) error { if config == nil { return errors.New("run logger config is nil") } + if moduleName == "" { + return initDefaultRunLog(config) + } + if ModuleRunLog[moduleName] != nil && ModuleRunLog[moduleName].isInit() { + ModuleRunLog[moduleName].Warn("run logger for module %s has been initialized", moduleName) + return nil + } + ModuleRunLog[moduleName] = new(logger) + if ModuleRunLog[moduleName] == nil { + return errors.New("malloc new logger failed") + } + if err := ModuleRunLog[moduleName].setLogger(config); err != nil { + return err + } + if !ModuleRunLog[moduleName].isInit() { + return fmt.Errorf("run logger for module %s init failed", moduleName) + } + return nil +} + +func initDefaultRunLog(config *LogConfig) error { if RunLog != nil && RunLog.isInit() { - RunLog.Warn("run logger is been initialized") + RunLog.Warn("run logger has been initialized") return nil } RunLog = new(logger) if RunLog == nil { - return errors.New("malloc new logger flied") + return errors.New("malloc new logger failed") } if err := RunLog.setLogger(config); err != nil { return err } if !RunLog.isInit() { - return errors.New("run logger init failed") + return fmt.Errorf("run logger for module init failed") } return nil } diff --git a/component/taskd/taskd/go/backend_api.go b/component/taskd/taskd/go/backend_api.go index decee1461586e3d953a13d6e213ac6a300f619e6..f6cfb47d947fd1c818e6c03d033635c6604e2474 100644 --- a/component/taskd/taskd/go/backend_api.go +++ b/component/taskd/taskd/go/backend_api.go @@ -21,12 +21,12 @@ import ( "fmt" "os" "os/signal" + "path/filepath" "syscall" "time" "ascend-common/common-utils/hwlog" "taskd/common/constant" - "taskd/common/utils" "taskd/framework_backend/worker/monitor/profiling" ) @@ -41,11 +41,11 @@ func InitTaskMonitor(rank int, upperLimitOfDiskInMb int) C.int { profiling.SetDiskUsageUpperLimitMB(upperLimitOfDiskInMb) profiling.GlobalRankId = rank // init so should not use print to avoid impact on system calls - err := utils.InitHwLog(ctx) - if err != nil { - fmt.Println(err) - return C.int(1) - } + //retCode := InitHwLog("monitor.log", "monitor-1") + //if retCode != C.int(0) { + // fmt.Println(retCode) + // return C.int(1) + //} if err := profiling.InitMspti(); err != nil { hwlog.RunLog.Error(err) return C.int(1) @@ -87,5 +87,45 @@ func StartMonitorClient() C.int { return C.int(0) } +// InitHwLog init hwlog + +//export InitHwLog +func InitHwLog(logFileName *C.char, moduleName *C.char) C.int { + var logFile string + goLogFileName := C.GoString(logFileName) + goModuleName := C.GoString(moduleName) + logFilePath := os.Getenv(constant.LogFilePathEnv) + fmt.Printf("LogFilePathEnv: %s\n", logFilePath) + fmt.Printf("logFileName: %d\n", len(goLogFileName)) + fmt.Printf("moduleName: %d\n", len(goModuleName)) + if logFilePath == "" { + logFile = filepath.Join(constant.DefaultLogFilePath, goModuleName, goLogFileName) + } else { + logFile = filepath.Join(logFilePath, goModuleName, goLogFileName) + } + go func() { + cnt := 1 + for { + time.Sleep(time.Second) + hwlog.ModuleRunLog[goModuleName].Infof("hwlog cnt:%d", cnt) + cnt++ + } + }() + hwLogConfig := hwlog.LogConfig{ + LogFileName: logFile, + LogLevel: constant.DefaultLogLevel, + MaxBackups: constant.DefaultMaxBackups, + MaxAge: constant.DefaultMaxAge, + MaxLineLength: constant.DefaultMaxLineLength, + // do not print to screen to avoid influence training log + OnlyToFile: false, + } + if err := hwlog.InitRunLogger(&hwLogConfig, goModuleName, context.Background()); err != nil { + fmt.Printf("hwlog init failed, error is %v\n", err) + return C.int(1) + } + return C.int(0) +} + func main() { } diff --git a/component/taskd/taskd/go/common/utils/utils.go b/component/taskd/taskd/go/common/utils/utils.go index 7cbc81989b45bc8b80be8b8ec42f9a469902dfb9..62b6703d35179f2fc0f5968aee2b6b0cb6397ff3 100644 --- a/component/taskd/taskd/go/common/utils/utils.go +++ b/component/taskd/taskd/go/common/utils/utils.go @@ -15,40 +15,3 @@ // Package utils is to provide go runtime utils package utils -import ( - "context" - "fmt" - "os" - "path/filepath" - "strconv" - - "ascend-common/common-utils/hwlog" - "taskd/common/constant" - "taskd/framework_backend/worker/monitor/profiling" -) - -// InitHwLog init hwlog -func InitHwLog(ctx context.Context) error { - var logFile string - logFilePath := os.Getenv(constant.LogFilePathEnv) - logFileName := "taskd-worker-" + strconv.Itoa(profiling.GlobalRankId) + ".log" - if logFilePath == "" { - logFile = constant.DefaultLogFilePath + logFileName - } else { - logFile = filepath.Join(logFilePath, logFileName) - } - hwLogConfig := hwlog.LogConfig{ - LogFileName: logFile, - LogLevel: constant.DefaultLogLevel, - MaxBackups: constant.DefaultMaxBackups, - MaxAge: constant.DefaultMaxAge, - MaxLineLength: constant.DefaultMaxLineLength, - // do not print to screen to avoid influence training log - OnlyToFile: true, - } - if err := hwlog.InitRunLogger(&hwLogConfig, context.Background()); err != nil { - fmt.Printf("hwlog init failed, error is %v\n", err) - return err - } - return nil -} diff --git a/component/taskd/taskd/python/constants/constants.py b/component/taskd/taskd/python/constants/constants.py index f73e350840e45c3a8fe9048d0e9778f0f76fc952..596952702f4483f641e277f418b86d650a186219 100644 --- a/component/taskd/taskd/python/constants/constants.py +++ b/component/taskd/taskd/python/constants/constants.py @@ -34,7 +34,8 @@ TASKD_LOG_PATH = 'TASKD_LOG_PATH' # logger default config LOG_MAX_LINE_LENGTH = 1023 -LOG_SIMPLE_FORMAT = '[%(levelname)s] %(asctime)s.%(msecs)06d %(process)d %(filename)s:%(lineno)d %(message)s' +LOG_SIMPLE_FORMAT = ('[%(levelname)s] %(asctime)s %(process)d %(name)s:%(module)s/%(filename)s:%(' + 'lineno)d ''%(message)s') LOG_DATE_FORMAT = '%Y/%m/%d %H:%M:%S' LOG_BACKUP_FORMAT = '%Y-%m-%dT%H-%M-%S.%f' LOG_BACKUP_PATTERN = '\d{4}-\d{2}-\d{2}T\d{2}-\d{2}-\d{2}\.\d{3}' diff --git a/component/taskd/taskd/python/cython_api/cython_api.py b/component/taskd/taskd/python/cython_api/cython_api.py index e15f12b9a770f6deac972c59b7bf918f451fa51b..f44010b44e280c3f3fe34ff520da049ad13de16b 100644 --- a/component/taskd/taskd/python/cython_api/cython_api.py +++ b/component/taskd/taskd/python/cython_api/cython_api.py @@ -16,14 +16,14 @@ # ============================================================================== import ctypes import os -from taskd.python.utils.log import run_log +# from taskd.python.utils.log import run_log from taskd.python.constants.constants import LIB_SO_NAME, LIB_SO_PATH try: mode = os.RTLD_LAZY | os.RTLD_LOCAL lib_path = os.path.join(os.path.dirname(__file__), LIB_SO_PATH, LIB_SO_NAME) lib = ctypes.CDLL(lib_path, mode=mode) - run_log.info(f"{LIB_SO_NAME} loaded successfully") + # run_log.info(f"{LIB_SO_NAME} loaded successfully") except OSError as e: lib = None - run_log.info(f"{LIB_SO_NAME} loaded failed： {e}") + # run_log.info(f"{LIB_SO_NAME} loaded failed： {e}") diff --git a/component/taskd/taskd/python/utils/log/logger.py b/component/taskd/taskd/python/utils/log/logger.py index 74eaba1e21e6b2e3bce326d31dfe55fd2ee7fc6e..759571de1a62f18ca673945fb6dbcee2bfcf42a7 100644 --- a/component/taskd/taskd/python/utils/log/logger.py +++ b/component/taskd/taskd/python/utils/log/logger.py @@ -14,12 +14,13 @@ # See the License for the specific language governing permissions and # limitations under the License. # ============================================================================== +import ctypes import datetime import logging import os import re import sys -from logging.handlers import RotatingFileHandler +import time from taskd.python.constants.constants import (LOG_DEFAULT_FILE_PATH, LOG_MAX_LINE_LENGTH, LOG_DATE_FORMAT, LOG_SIMPLE_FORMAT, LOG_DEFAULT_FILE, LOG_DEFAULT_FILE_NAME, @@ -27,6 +28,8 @@ from taskd.python.constants.constants import (LOG_DEFAULT_FILE_PATH, LOG_MAX_LIN LOG_PRIVILEGE, LOG_DIR_PRIVILEGE, LOG_BACKUP_PATTERN, TASKD_LOG_STDOUT, TASKD_LOG_PATH, TASKD_FILE_LOG_LEVEL, TASKD_STD_LOG_LEVEL) +from taskd.python.cython_api import cython_api +from taskd.python.cython_api.cython_api import lib from taskd.python.utils.validator import FileValidator @@ -48,75 +51,16 @@ class MaxLengthFormatter(logging.Formatter): return msg[:self.max_length] + '...' return msg - -class CustomRotatingHandler(RotatingFileHandler): - ''' - Custom RotatingFileHandler to backup same format log file - ''' - - def __init__(self, filename, maxBytes=0, backupCount=0, encoding=None, delay=None): - super().__init__( - filename, maxBytes=maxBytes, - backupCount=backupCount, - encoding=encoding, - delay=delay - ) - - def rotation_filename(self, default_name): - base, ext = os.path.splitext(self.baseFilename) - back_time = datetime.datetime.now(tz=datetime.timezone.utc).strftime(LOG_BACKUP_FORMAT)[:-3] - return f"{base}-{back_time}{ext}" - - def doRollover(self): - """ - rewrite to do roll log file - """ - if self.stream: - self.stream.close() - self.stream = None - - # create backup file name and rename the current log file - backup_file_name = self.rotation_filename(self.baseFilename) - if os.path.exists(backup_file_name): - os.remove(backup_file_name) - os.rename(self.baseFilename, backup_file_name) - - # clear backup files that exceed the file limit - if self.backupCount > 0: - dir_name = os.path.dirname(self.baseFilename) - base_filename = os.path.basename(self.baseFilename) - base, ext = os.path.splitext(base_filename) - - # match all backup files that match the format - pattern = re.compile(rf'^({re.escape(base)}-{LOG_BACKUP_PATTERN}{re.escape(ext)})$') - backups = [] - - for filename in os.listdir(dir_name): - match = pattern.match(filename) - if match: - timestamp_str = match.group(1) - # get timestamp str for sort file - timestamp_str = timestamp_str[len(base) + 1:-len(ext)] - - try: - # resolve timestamps in file names - ts = datetime.datetime.strptime( - timestamp_str, LOG_BACKUP_FORMAT) - backups.append((filename, ts)) - except ValueError: - continue - - # sort by time (old → new) - backups.sort(key=lambda x: x[1]) - - # delete old backups that exceed the reserved quantity - while len(backups) > self.backupCount: - oldest = backups.pop(0) - os.remove(os.path.join(dir_name, oldest[0])) - - # create new log file - if not self.delay: - self.stream = self._open() + def formatTime(self, record, datefmt=None): + ct = time.localtime(record.created) + timestamp = record.created + seconds = int(timestamp) + microseconds = int((timestamp - seconds) * 1000000) + if datefmt: + s = time.strftime(datefmt, ct) + else: + s = time.strftime(LOG_DATE_FORMAT, ct) + return f"{s}.{microseconds:06d}" class LogConfig: @@ -124,15 +68,22 @@ class LogConfig: Log Config include logger configuration """ - def __init__(self): - self.log_max_line_length = LOG_MAX_LINE_LENGTH - self.file_log_level = logging.INFO - self.std_log_level = logging.INFO - self.log_format = LOG_SIMPLE_FORMAT - self.log_file = LOG_DEFAULT_FILE - self.log_std_out = True - self.log_backup_count = LOG_DEFAULT_BACKUP_COUNT - self.log_max_bytes = LOG_DEFAULT_MAX_BYTES + def __init__(self, log_file, + log_max_line_length=LOG_MAX_LINE_LENGTH, + file_log_level=logging.INFO, + std_log_level=logging.INFO, + log_format=LOG_SIMPLE_FORMAT, + log_std_out=True, + log_backup_count=LOG_DEFAULT_BACKUP_COUNT, + log_max_bytes=LOG_DEFAULT_MAX_BYTES): + self.log_max_line_length = log_max_line_length + self.file_log_level = file_log_level + self.std_log_level = std_log_level + self.log_format = log_format + self.log_file = log_file + self.log_std_out = log_std_out + self.log_backup_count = log_backup_count + self.log_max_bytes = log_max_bytes self.build_config() def build_config(self): @@ -141,6 +92,8 @@ class LogConfig: self.build_log_stdout() def build_log_path(self): + if self.log_file != "": + return log_path = os.getenv(TASKD_LOG_PATH) if log_path is None: log_path = LOG_DEFAULT_FILE_PATH @@ -183,25 +136,6 @@ def _set_loglevel(logger: logging.Logger, level: int): handler.setLevel(level) -def _set_rotator(logger: logging.Logger, rotate_func: callable): - for handler in logger.handlers: - handler.rotator = rotate_func - - -def _log_rotator(source: str, dest: str) -> None: - try: - if os.path.exists(source): - os.rename(source, dest) - os.chmod(dest, mode=LOG_PRIVILEGE) - if not os.path.exists(source): - os.mknod(source, mode=LOG_PRIVILEGE) - else: - _exit_file_process(source) - except Exception as e: - logging.error('exception occurred while rotating log: %s', str(e)) - return - - def _exit_file_process(log_path: str) -> None: """ Handle log file when file is already existed. @@ -224,16 +158,17 @@ def _get_stream_handler(cfg: LogConfig): def _get_file_handler(cfg: LogConfig): - file_handler = CustomRotatingHandler(cfg.log_file, maxBytes=cfg.log_max_bytes, backupCount=cfg.log_backup_count) + file_handler = logging.FileHandler(cfg.log_file) file_handler.setLevel(cfg.file_log_level) file_handler.setFormatter(logging.Formatter(cfg.log_format, datefmt=LOG_DATE_FORMAT)) return file_handler -def _get_logger() -> logging.Logger: +def get_logger(sub_module_name: str, log_file_name: str, **kwargs) -> logging.Logger: # init logger and log config - log_cfg = LogConfig() - logger = logging.getLogger("taskd") + log_file = os.path.join(LOG_DEFAULT_FILE_PATH, sub_module_name, log_file_name) + log_cfg = LogConfig(log_file=log_file, **kwargs) + logger = logging.getLogger(f"taskd.{sub_module_name}") logger.setLevel(logging.DEBUG) @@ -243,9 +178,30 @@ def _get_logger() -> logging.Logger: # set log write to file logger.addHandler(_get_file_handler(log_cfg)) - _set_rotator(logger, rotate_func=_log_rotator) _set_formatter(logger, log_cfg.log_format) return logger -run_log = _get_logger() +def init_go_logger(log_file_name, sub_module_name, **kwargs): + lib.InitHwLog.argtypes = [ctypes.c_char_p, ctypes.c_char_p] + lib.InitHwLog.restype = ctypes.c_int + InitHwLog = cython_api.lib.InitHwLog + log_file_name_bytes = log_file_name.encode('utf-8') + sub_module_name_bytes = sub_module_name.encode('utf-8') + InitHwLog(log_file_name_bytes, sub_module_name_bytes) + + +worker_log = get_logger("worker", log_file_name='worker.log') +monitor_log = get_logger("monitor", log_file_name='monitor.log') +init_go_logger(log_file_name="worker.log", sub_module_name="worker") +init_go_logger(log_file_name="master.log", sub_module_name="master") + +if __name__ == "__main__": + monitor_log.info("monitor") + cnt = 0 + while True: + cnt += 1 + worker_log.warning(f"workerworkerworkerworkerworkerworkerworkerworkerworkerworker {cnt}") + if cnt>1000000: + break + monitor_log.warning("monitor")