1# Copyright 2020 Huawei Technologies Co., Ltd 2# 3# Licensed under the Apache License, Version 2.0 (the "License"); 4# you may not use this file except in compliance with the License. 5# You may obtain a copy of the License at 6# 7# http://www.apache.org/licenses/LICENSE-2.0 8# 9# Unless required by applicable law or agreed to in writing, software 10# distributed under the License is distributed on an "AS IS" BASIS, 11# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 12# See the License for the specific language governing permissions and 13# limitations under the License. 14# ============================================================================ 15""" 16log test 17""" 18import logging 19import os 20import re 21import shutil 22import sys 23import time 24 25 26def test_log_stdout(): 27 # Clean up environment variables 28 _rm_env_config() 29 # print the logs without raising an exception. 30 from mindspore import log as logger 31 log_str = 'print informations' 32 logger.error("1 test log message error :%s", log_str) 33 logger.info("2 test log message info :%s", log_str) 34 logger.warning("3 test log message warning :%s", log_str) 35 logger.debug("4 test log message debug:%s", log_str) 36 # Clean up _global_logger to avoid affecting for next usecase 37 _clear_logger(logger) 38 39 40def test_log_default(): 41 _rm_env_config() 42 from mindspore import log as logger 43 configdict = logger.get_log_config() 44 targetdict = {'GLOG_v': '2', 'GLOG_logtostderr': '1'} 45 assert configdict == targetdict 46 # Clean up _global_logger to avoid affecting for next usecase 47 _clear_logger(logger) 48 49 50def test_log_setlevel(): 51 _rm_env_config() 52 os.environ['GLOG_v'] = '0' 53 from mindspore import log as logger 54 # logger_instance = logger._get_logger() 55 # del logger_instance 56 loglevel = logger.get_level() 57 log_str = 'print debug informations' 58 logger.debug("5 test log message debug:%s", log_str) 59 assert loglevel == '0' 60 # Clean up _global_logger to avoid affecting for next usecase 61 _clear_logger(logger) 62 63 64def test_log_file(): 65 """ 66 test the log content written in log file 67 """ 68 _rm_env_config() 69 file_path = '/tmp/log/mindspore_test' 70 os.environ['GLOG_v'] = '2' 71 os.environ['GLOG_logtostderr'] = '0' 72 os.environ['GLOG_log_dir'] = file_path 73 if os.path.exists(file_path): 74 shutil.rmtree(file_path) 75 filename = '' 76 os.makedirs(file_path, exist_ok=True) 77 from mindspore import log as logger 78 _clear_logger(logger) 79 logger.warning("test log message warning") 80 file_path += '/rank_0/logs' 81 f_list = os.listdir(file_path) 82 # print f_list 83 for file_name in f_list: 84 if file_name.startswith('mindspore.log'): 85 filename = f'{file_path}/{file_name}' 86 cmd = f'cat {filename}' 87 result = os.popen(cmd).read() 88 # pylint: disable=anomalous-backslash-in-string 89 90 pattern = "\[WARNING\] ME\(.*[0-9]:.*[0-9]\,.*[a-zA-Z0-9]\):.* " \ 91 "\[.*:.*[0-9]\] test log message warning" 92 match_obj = re.match(pattern, result) 93 # Clear test file 94 if os.path.exists(file_path): 95 shutil.rmtree(file_path) 96 97 assert match_obj 98 # Clean up _global_logger to avoid affecting for next usecase 99 _clear_logger(logger) 100 101def test_log_backup_count(): 102 """ 103 test backup count 104 """ 105 # logger.reset_log_config(level=logging.INFO, console=False, 106 # filepath=file_path, maxBytes=1000, backupCount=10) 107 _rm_env_config() 108 file_path = '/tmp/log/mindspore_test' 109 os.environ['GLOG_v'] = '1' 110 os.environ['GLOG_logtostderr'] = '0' 111 os.environ['GLOG_log_dir'] = file_path 112 os.environ['logger_maxBytes'] = '1000' 113 os.environ['logger_backupCount'] = '10' 114 115 if os.path.exists(file_path): 116 shutil.rmtree(file_path) 117 os.makedirs(file_path, exist_ok=True) 118 from mindspore import log as logger 119 _clear_logger(logger) 120 121 log_count = 100 122 for i in range(0, log_count, 1): 123 logger.warning("test log message warning %r", i) 124 125 file_path += '/rank_0/logs' 126 cmd = f'cd {file_path};ls -l | grep \'mindspore.log.*\'|wc -l' 127 backup_count = '11' 128 file_count = os.popen(cmd).read().strip() 129 130 if os.path.exists(file_path): 131 shutil.rmtree(file_path) 132 assert file_count == backup_count 133 # Clean up _global_logger to avoid affecting for next usecase 134 _clear_logger(logger) 135 136 137def test_log_verify_envconfig(): 138 """ 139 test reset config 140 """ 141 dictlist = [] 142 from mindspore import log as logger 143 file_path = '/tmp' 144 145 # level is not a number 146 _rm_env_config() 147 os.environ['GLOG_v'] = 'test' 148 verify_dict_0 = logger._get_env_config() 149 150 # level is not in range 151 _rm_env_config() 152 os.environ['GLOG_v'] = '100' 153 verify_dict_1 = logger._get_env_config() 154 155 # console is not a number 156 _rm_env_config() 157 os.environ['GLOG_logtostderr'] = 'test' 158 verify_dict_2 = logger._get_env_config() 159 160 # console is not in range 161 _rm_env_config() 162 os.environ['GLOG_logtostderr'] = '6' 163 verify_dict_3 = logger._get_env_config() 164 165 # path does not exist 166 _rm_env_config() 167 os.environ['GLOG_logtostderr'] = '0' 168 verify_dict_4 = logger._get_env_config() 169 170 # path is not configured 171 _rm_env_config() 172 os.environ['GLOG_logtostderr'] = '0' 173 verify_dict_5 = logger._get_env_config() 174 175 # logger_maxBytes is not a number 176 _rm_env_config() 177 os.environ['GLOG_logtostderr'] = '0' 178 os.environ['logger_maxBytes'] = 'test' 179 os.environ['logger_backupCount'] = '10' 180 verify_dict_6 = logger._get_env_config() 181 182 # logger_maxBytes is a negative number 183 _rm_env_config() 184 os.environ['GLOG_logtostderr'] = '0' 185 os.environ['logger_maxBytes'] = '-1' 186 os.environ['logger_backupCount'] = '10' 187 verify_dict_7 = logger._get_env_config() 188 189 # logger_backupCount is not a number 190 _rm_env_config() 191 os.environ['GLOG_logtostderr'] = '0' 192 os.environ['logger_maxBytes'] = '0' 193 os.environ['logger_backupCount'] = 'test' 194 verify_dict_8 = logger._get_env_config() 195 196 # logger_backupCount is a negative number 197 _rm_env_config() 198 os.environ['GLOG_logtostderr'] = '0' 199 os.environ['logger_maxBytes'] = '0' 200 os.environ['logger_backupCount'] = '-1' 201 verify_dict_9 = logger._get_env_config() 202 203 for i in range(0, 10, 1): 204 variable_name = f'verify_dict_{i}' 205 dictlist.append(locals()[variable_name]) 206 207 for verify_dict in dictlist: 208 try: 209 logger._verify_config(verify_dict) 210 except ValueError as ve: 211 print(ve) 212 assert True 213 except TypeError as te: 214 print(te) 215 assert True 216 else: 217 assert False 218 # Clean up _global_logger to avoid affecting for next usecase 219 _clear_logger(logger) 220 221 222def test_log_repeated_print(): 223 """ 224 test Log repeated printing 225 # Print one log is right, otherwise error 226 """ 227 _rm_env_config() 228 from mindspore import log as logger 229 py_logging = logging.getLogger() 230 handler = logging.StreamHandler(sys.stdout) 231 handler.setLevel(logging.DEBUG) 232 py_logging.addHandler(handler) 233 logger.info("test log message info test ") 234 # Clean up _global_logger to avoid affecting for next usecase 235 _clear_logger(logger) 236 237 238def test_log_getconfig(): 239 _rm_env_config() 240 os.environ['GLOG_v'] = '3' 241 os.environ['GLOG_logtostderr'] = '0' 242 os.environ['GLOG_log_dir'] = '/tmp/log/' 243 os.environ['logger_maxBytes'] = '1000' 244 os.environ['logger_backupCount'] = '10' 245 from mindspore import log as logger 246 _clear_logger(logger) 247 logger.info("test log message info test") 248 configdict = logger.get_log_config() 249 targetdict = {'GLOG_v': '3', 'GLOG_log_dir': '/tmp/log/rank_0/logs', 250 'GLOG_logtostderr': '0', 'logger_maxBytes': 1000, 251 'logger_backupCount': 10, 'GLOG_stderrthreshold': '2'} 252 assert configdict == targetdict 253 # Clean up _global_logger to avoid affecting for next usecase 254 _clear_logger(logger) 255 256 257def test_log_perf(): 258 """ 259 Performance test with python logging 260 """ 261 _rm_env_config() 262 os.environ['GLOG_v'] = '3' 263 from mindspore import log as logger 264 loglevel = logging.ERROR 265 logging.basicConfig() 266 py_logging = logging.getLogger() 267 py_logging.setLevel(loglevel) 268 269 log_count = 100000 270 271 print("logger level:", logger.get_level()) 272 print("py_logging level:", py_logging.getEffectiveLevel()) 273 274 # Calculate PY logging execution time 275 start_time_py_logging = int(round(time.time() * 1000)) 276 277 for i in range(0, log_count, 1): 278 py_logging.info("test log message info :%r", i) 279 280 end_time_py_logging = int(round(time.time() * 1000)) 281 time_diff_py_logging = end_time_py_logging - start_time_py_logging 282 283 # Calculate MS logger execution time 284 start_time_logger = int(round(time.time() * 1000)) 285 286 for i in range(0, log_count, 1): 287 logger.info("test log message info :%r", i) 288 289 end_time_logger = int(round(time.time() * 1000)) 290 time_diff_logger = end_time_logger - start_time_logger 291 292 # Calculate time difference 293 time_diff = time_diff_logger - time_diff_py_logging 294 strprint = f'time difference between MS logger ' \ 295 f'and Python logging: {time_diff} ms' 296 print(strprint) 297 std_time = 2000 298 assert time_diff < std_time 299 # Clean up _global_logger to avoid affecting for next usecase 300 _clear_logger(logger) 301 302 303def test_log_ms_import(): 304 _rm_env_config() 305 import mindspore as ms 306 configdict = ms.get_log_config() 307 targetdict = {'GLOG_v': '2', 'GLOG_logtostderr': '1'} 308 level = ms.get_level() 309 assert configdict == targetdict and level == '2' 310 311 312def _clear_logger(logger): 313 if logger._global_logger: 314 for handler in logger._global_logger.handlers: 315 logger._global_logger.removeHandler(handler) 316 logger._global_logger = None 317 318 319def _rm_env_config(): 320 envlist = ['GLOG_v', 'GLOG_logtostderr', 'GLOG_log_dir', 'logger_maxBytes', 'logger_backupCount'] 321 for env in envlist: 322 if os.environ.get(env): 323 del os.environ[env] 324