1#!/usr/bin/env python3 2# coding=utf-8 3 4# 5# Copyright (c) 2020-2021 Huawei Device Co., Ltd. 6# Licensed under the Apache License, Version 2.0 (the "License"); 7# you may not use this file except in compliance with the License. 8# You may obtain a copy of the License at 9# 10# http://www.apache.org/licenses/LICENSE-2.0 11# 12# Unless required by applicable law or agreed to in writing, software 13# distributed under the License is distributed on an "AS IS" BASIS, 14# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 15# See the License for the specific language governing permissions and 16# limitations under the License. 17# 18 19import logging 20import sys 21import time 22from logging.handlers import RotatingFileHandler 23 24from _core.constants import LogType 25from _core.plugin import Plugin 26from _core.plugin import get_plugin 27from _core.exception import ParamError 28 29 30__all__ = ["Log", "platform_logger", "device_logger", "shutdown", 31 "add_task_file_handler", "remove_task_file_handler", 32 "change_logger_level", "add_encrypt_file_handler", 33 "remove_encrypt_file_handler"] 34 35_HANDLERS = [] 36_LOGGERS = [] 37MAX_LOG_LENGTH = 10 * 1024 * 1024 38MAX_ENCRYPT_LOG_LENGTH = 5 * 1024 * 1024 39 40 41class Log: 42 task_file_handler = None 43 44 def __init__(self): 45 self.level = logging.INFO 46 self.handlers = [] 47 self.loggers = {} 48 self.task_file_handler = None 49 self.encrypt_file_handler = None 50 51 def __initial__(self, log_handler_flag, log_file=None, level=None, 52 log_format=None): 53 if _LOGGERS: 54 return 55 56 self.handlers = [] 57 if log_file and "console" in log_handler_flag: 58 file_handler = RotatingFileHandler( 59 log_file, mode="a", maxBytes=MAX_LOG_LENGTH, backupCount=5, 60 encoding="UTF-8") 61 file_handler.setFormatter(logging.Formatter(log_format)) 62 self.handlers.append(file_handler) 63 if "console" in log_handler_flag: 64 stream_handler = logging.StreamHandler(sys.stdout) 65 stream_handler.setFormatter(logging.Formatter(log_format)) 66 self.handlers.append(stream_handler) 67 68 if level: 69 self.level = level 70 self.loggers = {} 71 self.task_file_handler = None 72 _HANDLERS.extend(self.handlers) 73 74 def set_level(self, level): 75 self.level = level 76 77 def __logger__(self, name=None): 78 if not name: 79 return _init_global_logger(name) 80 elif name in self.loggers: 81 return self.loggers.get(name) 82 else: 83 log = self.loggers.setdefault(name, FrameworkLog(name)) 84 _LOGGERS.append(log) 85 log.platform_log.setLevel(self.level) 86 for handler in self.handlers: 87 log.platform_log.addHandler(handler) 88 if self.task_file_handler: 89 log.add_task_log(self.task_file_handler) 90 return log 91 92 def add_task_file_handler(self, log_file): 93 from xdevice import Variables 94 file_handler = RotatingFileHandler( 95 log_file, mode="a", maxBytes=MAX_LOG_LENGTH, backupCount=5, 96 encoding="UTF-8") 97 file_handler.setFormatter(logging.Formatter( 98 Variables.report_vars.log_format)) 99 self.task_file_handler = file_handler 100 for _, log in self.loggers.items(): 101 log.add_task_log(self.task_file_handler) 102 103 def remove_task_file_handler(self): 104 if self.task_file_handler is None: 105 return 106 for _, log in self.loggers.items(): 107 log.remove_task_log(self.task_file_handler) 108 self.task_file_handler.close() 109 self.task_file_handler = None 110 111 def add_encrypt_file_handler(self, log_file): 112 from xdevice import Variables 113 114 file_handler = \ 115 EncryptFileHandler(log_file, mode="ab", 116 max_bytes=MAX_ENCRYPT_LOG_LENGTH, 117 backup_count=5, encoding="utf-8") 118 file_handler.setFormatter(logging.Formatter( 119 Variables.report_vars.log_format)) 120 self.encrypt_file_handler = file_handler 121 for _, log in self.loggers.items(): 122 log.add_encrypt_log(self.encrypt_file_handler) 123 124 def remove_encrypt_file_handler(self): 125 if self.encrypt_file_handler is None: 126 return 127 for _, log in self.loggers.items(): 128 log.remove_encrypt_log(self.encrypt_file_handler) 129 self.encrypt_file_handler.close() 130 self.encrypt_file_handler = None 131 132 133class FrameworkLog: 134 135 def __init__(self, name): 136 self.name = name 137 self.platform_log = logging.Logger(name) 138 self.task_log = None 139 self.encrypt_log = None 140 141 def set_level(self, level): 142 # apply to dynamic change logger level, and 143 # only change the level of platform log 144 cache = getattr(self.platform_log, "_cache", None) 145 if cache and isinstance(cache, dict): 146 cache.clear() 147 self.platform_log.setLevel(level) 148 149 def add_task_log(self, handler): 150 if self.task_log: 151 return 152 self.task_log = logging.Logger(self.name) 153 log_level = getattr(sys, "log_level", logging.INFO) if hasattr( 154 sys, "log_level") else logging.DEBUG 155 self.task_log.setLevel(log_level) 156 self.task_log.addHandler(handler) 157 158 def remove_task_log(self, handler): 159 if not self.task_log: 160 return 161 self.task_log.removeHandler(handler) 162 self.task_log = None 163 164 def add_encrypt_log(self, handler): 165 if self.encrypt_log: 166 return 167 self.encrypt_log = logging.Logger(self.name) 168 log_level = getattr(sys, "log_level", logging.INFO) if hasattr( 169 sys, "log_level") else logging.DEBUG 170 self.encrypt_log.setLevel(log_level) 171 self.encrypt_log.addHandler(handler) 172 173 def remove_encrypt_log(self, handler): 174 if not self.encrypt_log: 175 return 176 self.encrypt_log.removeHandler(handler) 177 self.encrypt_log = None 178 179 def info(self, msg, *args, **kwargs): 180 additional_output = self._get_additional_output(**kwargs) 181 updated_msg = self._update_msg(additional_output, msg) 182 self.platform_log.info(updated_msg, *args) 183 if self.task_log: 184 self.task_log.info(updated_msg, *args) 185 if self.encrypt_log: 186 self.encrypt_log.info(updated_msg, *args) 187 188 def debug(self, msg, *args, **kwargs): 189 additional_output = self._get_additional_output(**kwargs) 190 updated_msg = self._update_msg(additional_output, msg) 191 from _core.report.encrypt import check_pub_key_exist 192 if not check_pub_key_exist(): 193 self.platform_log.debug(updated_msg, *args) 194 if self.task_log: 195 self.task_log.debug(updated_msg, *args) 196 else: 197 if self.encrypt_log: 198 self.encrypt_log.debug(updated_msg, *args) 199 200 def error(self, msg, *args, **kwargs): 201 error_no = kwargs.get("error_no", "00000") 202 additional_output = self._get_additional_output(error_no, **kwargs) 203 updated_msg = self._update_msg(additional_output, msg) 204 205 self.platform_log.error(updated_msg, *args) 206 if self.task_log: 207 self.task_log.error(updated_msg, *args) 208 if self.encrypt_log: 209 self.encrypt_log.error(updated_msg, *args) 210 211 def warning(self, msg, *args, **kwargs): 212 additional_output = self._get_additional_output(**kwargs) 213 updated_msg = self._update_msg(additional_output, msg) 214 215 self.platform_log.warning(updated_msg, *args) 216 if self.task_log: 217 self.task_log.warning(updated_msg, *args) 218 if self.encrypt_log: 219 self.encrypt_log.warning(updated_msg, *args) 220 221 def exception(self, msg, *args, **kwargs): 222 error_no = kwargs.get("error_no", "00000") 223 exc_info = kwargs.get("exc_info", True) 224 if exc_info is not True and exc_info is not False: 225 exc_info = True 226 additional_output = self._get_additional_output(error_no, **kwargs) 227 updated_msg = self._update_msg(additional_output, msg) 228 229 self.platform_log.exception(updated_msg, exc_info=exc_info, *args) 230 if self.task_log: 231 self.task_log.exception(updated_msg, exc_info=exc_info, *args) 232 if self.encrypt_log: 233 self.encrypt_log.exception(updated_msg, exc_info=exc_info, *args) 234 235 @classmethod 236 def _update_msg(cls, additional_output, msg): 237 msg = "[%s]" % msg if msg else msg 238 if msg and additional_output: 239 msg = "%s [%s]" % (msg, additional_output) 240 return msg 241 242 def _get_additional_output(self, error_number=None, **kwargs): 243 dict_str = self._get_dict_str(**kwargs) 244 if error_number: 245 additional_output = "ErrorNo=%s" % error_number 246 else: 247 return dict_str 248 249 if dict_str: 250 additional_output = "%s, %s" % (additional_output, dict_str) 251 return additional_output 252 253 @classmethod 254 def _get_dict_str(cls, **kwargs): 255 dict_str = "" 256 for key, value in kwargs.items(): 257 if key in ["error_no", "exc_info"]: 258 continue 259 dict_str = "%s%s=%s, " % (dict_str, key, value) 260 if dict_str: 261 dict_str = dict_str[:-2] 262 return dict_str 263 264 265def platform_logger(name=None): 266 plugins = get_plugin(Plugin.LOG, LogType.tool) 267 for log_plugin in plugins: 268 if log_plugin.get_plugin_config().enabled: 269 return log_plugin.__logger__(name) 270 return _init_global_logger(name) 271 272 273def device_logger(name=None): 274 plugins = get_plugin(Plugin.LOG, LogType.device) 275 for log_plugin in plugins: 276 if log_plugin.get_plugin_config().enabled: 277 return log_plugin.__logger__(name) 278 return _init_global_logger(name) 279 280 281def shutdown(): 282 # logging will be shutdown automatically, when the program exits. 283 # This function is used by testing. 284 for log in _LOGGERS: 285 for handler in log.handlers: 286 log.removeHandler(handler) 287 for handler in _HANDLERS: 288 handler.close() 289 _HANDLERS.clear() 290 _LOGGERS.clear() 291 292 293def add_task_file_handler(log_file=None): 294 if log_file is None: 295 return 296 plugins = get_plugin(Plugin.LOG, LogType.tool) 297 for log_plugin in plugins: 298 if log_plugin.get_plugin_config().enabled: 299 log_plugin.add_task_file_handler(log_file) 300 301 302def remove_task_file_handler(): 303 plugins = get_plugin(Plugin.LOG, LogType.tool) 304 for log_plugin in plugins: 305 if log_plugin.get_plugin_config().enabled: 306 log_plugin.remove_task_file_handler() 307 308 309def add_encrypt_file_handler(log_file=None): 310 if log_file is None: 311 return 312 plugins = get_plugin(Plugin.LOG, LogType.tool) 313 for log_plugin in plugins: 314 if log_plugin.get_plugin_config().enabled: 315 log_plugin.add_encrypt_file_handler(log_file) 316 317 318def remove_encrypt_file_handler(): 319 plugins = get_plugin(Plugin.LOG, LogType.tool) 320 for log_plugin in plugins: 321 if log_plugin.get_plugin_config().enabled: 322 log_plugin.remove_encrypt_file_handler() 323 324 325def _init_global_logger(name=None): 326 handler = logging.StreamHandler(sys.stdout) 327 log_format = "[%(asctime)s] [%(name)s] [%(levelname)s] [%(message)s]" 328 handler.setFormatter(logging.Formatter(log_format)) 329 log = FrameworkLog(name) 330 log.platform_log.setLevel(logging.INFO) 331 log.platform_log.addHandler(handler) 332 return log 333 334 335def change_logger_level(leve_dict): 336 level_map = {"debug": logging.DEBUG, "info": logging.INFO} 337 if "console" in leve_dict.keys(): 338 level = leve_dict["console"] 339 if not level: 340 return 341 if str(level).lower() in level_map.keys(): 342 logger_level = level_map.get(str(level).lower(), logging.INFO) 343 344 # change level of loggers which will to be instantiated. 345 # Actually, it changes the level attribute in ToolLog, 346 # which will be used when instantiating the FrameLog object. 347 plugins = get_plugin(Plugin.LOG, LogType.tool) 348 for log_plugin in plugins: 349 log_plugin.set_level(logger_level) 350 # change level of loggers which have instantiated 351 for logger in _LOGGERS: 352 if getattr(logger, "setLevel", None): 353 logger.setLevel(logger_level) 354 elif getattr(logger, "set_level", None): 355 logger.set_level(logger_level) 356 357 if "file" in leve_dict.keys(): 358 level = leve_dict["file"] 359 if not level: 360 return 361 if str(level).lower() in level_map.keys(): 362 logger_level = level_map.get(str(level).lower(), logging.INFO) 363 setattr(sys, "log_level", logger_level) 364 365 366class EncryptFileHandler(RotatingFileHandler): 367 368 def __init__(self, filename, mode='ab', max_bytes=0, backup_count=0, 369 encoding=None, delay=False): 370 RotatingFileHandler.__init__(self, filename, mode, max_bytes, 371 backup_count, encoding, delay) 372 self.mode = mode 373 self.encrypt_error = None 374 375 def _open(self): 376 if not self.mode == "ab": 377 self.mode = "ab" 378 379 # baseFilename is the attribute in FileHandler 380 base_file_name = getattr(self, "baseFilename", None) 381 with open(base_file_name, self.mode) as encrypt_file: 382 return encrypt_file 383 384 def emit(self, record): 385 try: 386 if not self._encrypt_valid(): 387 return 388 389 # shouldRoller and doRoller is the method in RotatingFileHandler 390 should_rollover = getattr(self, "shouldRollover", None) 391 if callable(should_rollover) and should_rollover(record): 392 self.doRollover() 393 394 # stream is the attribute in StreamHandler 395 if not getattr(self, "stream", None): 396 setattr(self, "stream", self._open()) 397 msg = self.format(record) 398 stream = getattr(self, "stream", self._open()) 399 stream.write(msg) 400 self.flush() 401 except RecursionError: 402 raise 403 404 def _encrypt_valid(self): 405 from _core.report.encrypt import check_pub_key_exist 406 if check_pub_key_exist() and not self.encrypt_error: 407 return True 408 409 def format(self, record): 410 """ 411 Customize the implementation method. If the log format of the 412 framework changes, update the return value format of the method 413 in a timely manner. 414 :param record: logging.LogRecord 415 :return: bytes 416 """ 417 from _core.report.encrypt import do_rsa_encrypt 418 create_time = "{},{}".format( 419 time.strftime('%Y-%m-%d %H:%M:%S', time.localtime(record.created)), 420 "{:0>3d}".format(int("%d" % record.msecs))) 421 name = record.name 422 level_name = record.levelname 423 msg = record.msg 424 if msg and "%s" in msg: 425 msg = msg % record.args 426 info = "[%s] [%s] [%s] %s%s" \ 427 % (create_time, name, level_name, msg, "\n") 428 429 try: 430 return do_rsa_encrypt(info) 431 except ParamError as error: 432 error_no_str = \ 433 "ErrorNo={}".format(getattr(error, "error_no", "00113")) 434 info = "[%s] [%s] [%s] [%s] [%s]\n" % ( 435 create_time, name, "ERROR", error, error_no_str) 436 self.encrypt_error = bytes(info, "utf-8") 437 return self.encrypt_error 438