tools/calibration/logging.py

   1 """
   2 Copyright (C) 2018-2019 Intel Corporation
   3
   4 Licensed under the Apache License, Version 2.0 (the "License");
   5 you may not use this file except in compliance with the License.
   6 You may obtain a copy of the License at
   7
   8       http://www.apache.org/licenses/LICENSE-2.0
   9
  10 Unless required by applicable law or agreed to in writing, software
  11 distributed under the License is distributed on an "AS IS" BASIS,
  12 WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13 See the License for the specific language governing permissions and
  14 limitations under the License.
  15 """
  16
  17 import logging
  18 import logging.config
  19 import sys
  20 import warnings
  21 import threading
  22
  23 # TODO: move to utils
  24 _DEFAULT_LOGGER_NAME = 'openvino.tools.calibration'
  25 _DEFAULT_LOG_FILE = 'openvino.tools.calibration.log'
  26
  27 PRINT_INFO = logging.INFO + 5
  28 logging.addLevelName(PRINT_INFO, "PRINT_INFO")
  29
  30 _LOG_LEVEL_ENVIRON = "CALIBRATION_TOOL_LOG_LEVEL"
  31 # _LOGGING_LEVEL = logging.getLevelName(os.environ.get(_LOG_LEVEL_ENVIRON, PRINT_INFO))
  32 # TODO: refactoring: remove, use original line
  33 _LOGGING_LEVEL = "DEBUG"
  34
  35 lock = threading.Lock()
  36
  37
  38 class LoggingFormatter(logging.Formatter):
  39     def format(self, record: logging.LogRecord):
  40         if record.levelno == PRINT_INFO:
  41             return record.msg
  42         return super().format(record)
  43
  44
  45 class ConsoleHandler(logging.StreamHandler):
  46     def __init__(self, default_stream=sys.stdout):
  47         super().__init__(default_stream)
  48         self.default_stream = default_stream
  49         self.err_stream = sys.stderr
  50
  51     def emit(self, record):
  52         if record.levelno >= logging.WARNING:
  53             self.stream = self.err_stream
  54         else:
  55             self.stream = self.default_stream
  56         super().emit(record)
  57
  58
  59 _LOGGING_CONFIGURATION = {
  60     'version': 1,
  61     'disable_existing_loggers': False,
  62     'formatters': {
  63         'default': {
  64             '()': LoggingFormatter,
  65             'format': '%(asctime)s %(name)s %(levelname)s: %(message)s',
  66             'datefmt': '%H:%M:%S'
  67         },
  68         'detailed': {
  69             'format': '%(asctime)s %(name)s %(levelname)s: %(message)s'
  70         }
  71     },
  72     'handlers': {
  73         'console': {
  74             'level': 'DEBUG',
  75             '()': ConsoleHandler,
  76             'formatter': 'default',
  77         }
  78     },
  79
  80     'loggers': {
  81         _DEFAULT_LOGGER_NAME: {
  82             'handlers': ['console'],
  83             'level': _LOGGING_LEVEL,
  84             'propagate': False
  85         }
  86     }
  87 }
  88
  89 logging.config.dictConfig(_LOGGING_CONFIGURATION)
  90
  91 default_logger = logging.getLogger(_DEFAULT_LOGGER_NAME)
  92
  93
  94 def _warning_handler(message, category, filename, lineno):
  95     s = warnings.formatwarning(message, category, filename, lineno)
  96     default_logger.warning(s)
  97
  98
  99 warnings.showwarning = _warning_handler
 100
 101
 102 def get_logger(logger_name: str):
 103     if logger_name.startswith(_DEFAULT_LOGGER_NAME):
 104         return default_logger.getChild(logger_name)
 105     return logging.getLogger(logger_name)
 106
 107
 108 def error(msg, *args, **kwargs):
 109     with lock:
 110         default_logger.error(msg, *args, **kwargs)
 111
 112
 113 def warning(msg, *args, raise_warning=True, **kwargs):
 114     with lock:
 115         if raise_warning:
 116             warnings.warn(msg)
 117         else:
 118             default_logger.warning(msg, *args, **kwargs)
 119
 120
 121 def info(msg, *args, **kwargs):
 122     with lock:
 123         default_logger.info(msg, *args, **kwargs)
 124
 125
 126 def info_performance_counters(performance_counters: dict, *args, **kwargs):
 127     performance_counters_info = "\n\t{:<80} {:<15} {:<20} {:<15} {:<10}\n".format(
 128                 'name',
 129                 'layer_type',
 130                 'exet_type',
 131                 'status',
 132                 'real_time, us')
 133
 134     for layer_name, stats in performance_counters.items():
 135         performance_counters_info += "\t{:<80} {:<15} {:<20} {:<15} {:<10}\n".format(
 136             layer_name[0:77] + "..." if len(layer_name) > 80 else layer_name,
 137             stats['layer_type'],
 138             stats['exec_type'],
 139             stats['status'],
 140             stats['real_time'])
 141     info(performance_counters_info, *args, **kwargs)
 142
 143
 144 def info_layer_accuracy_drop(layers_accuracy_drop: list, *args, **kwargs):
 145     layer_accuracy_drop_text = "\n"
 146     for layer_accuracy_drop in layers_accuracy_drop:
 147         layer_accuracy_drop_text += "\t{0}: {1:.4f}%\n".format(
 148             layer_accuracy_drop.layer_name[0:77] + "..." if len(layer_accuracy_drop.layer_name) > 80 else layer_accuracy_drop.layer_name,
 149             layer_accuracy_drop.value * 100.0)
 150     info(layer_accuracy_drop_text, *args, **kwargs)
 151
 152
 153 def debug(msg, *args, **kwargs):
 154     with lock:
 155         default_logger.debug(msg, *args, **kwargs)
 156
 157
 158 def print_info(msg, *args, **kwargs):
 159     default_logger.log(PRINT_INFO, msg, *args, **kwargs)