1# Copyright 2011-2019, Damian Johnson and The Tor Project 2# See LICENSE for licensing information 3 4""" 5Functions to aid library logging. The default logging 6:data:`~stem.util.log.Runlevel` is usually NOTICE and above. 7 8**Stem users are more than welcome to listen for stem events, but these 9functions are not being vended to our users. They may change in the future, use 10them at your own risk.** 11 12**Module Overview:** 13 14:: 15 16 get_logger - provides the stem's Logger instance 17 logging_level - converts a runlevel to its logging number 18 escape - escapes special characters in a message in preparation for logging 19 20 log - logs a message at the given runlevel 21 log_once - logs a message, deduplicating if it has already been logged 22 trace - logs a message at the TRACE runlevel 23 debug - logs a message at the DEBUG runlevel 24 info - logs a message at the INFO runlevel 25 notice - logs a message at the NOTICE runlevel 26 warn - logs a message at the WARN runlevel 27 error - logs a message at the ERROR runlevel 28 29 LogBuffer - Buffers logged events so they can be iterated over. 30 |- is_empty - checks if there's events in our buffer 31 +- __iter__ - iterates over and removes the buffered events 32 33 log_to_stdout - reports further logged events to stdout 34 35.. data:: Runlevel (enum) 36 37 Enumeration for logging runlevels. 38 39 ========== =========== 40 Runlevel Description 41 ========== =========== 42 **ERROR** critical issue occurred, the user needs to be notified 43 **WARN** non-critical issue occurred that the user should be aware of 44 **NOTICE** information that is helpful to the user 45 **INFO** high level library activity 46 **DEBUG** low level library activity 47 **TRACE** request/reply logging 48 ========== =========== 49""" 50 51import logging 52 53import stem.prereq 54import stem.util.enum 55import stem.util.str_tools 56 57# Logging runlevels. These are *very* commonly used so including shorter 58# aliases (so they can be referenced as log.DEBUG, log.WARN, etc). 59 60Runlevel = stem.util.enum.UppercaseEnum('TRACE', 'DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERROR') 61TRACE, DEBUG, INFO, NOTICE, WARN, ERR = list(Runlevel) 62 63# mapping of runlevels to the logger module's values, TRACE and DEBUG aren't 64# built into the module 65 66LOG_VALUES = { 67 Runlevel.TRACE: logging.DEBUG - 5, 68 Runlevel.DEBUG: logging.DEBUG, 69 Runlevel.INFO: logging.INFO, 70 Runlevel.NOTICE: logging.INFO + 5, 71 Runlevel.WARN: logging.WARN, 72 Runlevel.ERROR: logging.ERROR, 73} 74 75logging.addLevelName(LOG_VALUES[TRACE], 'TRACE') 76logging.addLevelName(LOG_VALUES[NOTICE], 'NOTICE') 77 78LOGGER = logging.getLogger('stem') 79LOGGER.setLevel(LOG_VALUES[TRACE]) 80 81FORMATTER = logging.Formatter( 82 fmt = '%(asctime)s [%(levelname)s] %(message)s', 83 datefmt = '%m/%d/%Y %H:%M:%S', 84) 85 86# There's some messages that we don't want to log more than once. This set has 87# the messages IDs that we've logged which fall into this category. 88DEDUPLICATION_MESSAGE_IDS = set() 89 90# Adds a default nullhandler for the stem logger, suppressing the 'No handlers 91# could be found for logger "stem"' warning as per... 92# http://docs.python.org/release/3.1.3/library/logging.html#configuring-logging-for-a-library 93 94 95class _NullHandler(logging.Handler): 96 def __init__(self): 97 logging.Handler.__init__(self, level = logging.FATAL + 5) # disable logging 98 99 def emit(self, record): 100 pass 101 102 103if not LOGGER.handlers: 104 LOGGER.addHandler(_NullHandler()) 105 106 107def get_logger(): 108 """ 109 Provides the stem logger. 110 111 :returns: **logging.Logger** for stem 112 """ 113 114 return LOGGER 115 116 117def logging_level(runlevel): 118 """ 119 Translates a runlevel into the value expected by the logging module. 120 121 :param stem.util.log.Runlevel runlevel: runlevel to be returned, no logging if **None** 122 """ 123 124 if runlevel: 125 return LOG_VALUES[runlevel] 126 else: 127 return logging.FATAL + 5 128 129 130def is_tracing(): 131 """ 132 Checks if we're logging at the trace runlevel. 133 134 .. versionadded:: 1.6.0 135 136 :returns: **True** if we're logging at the trace runlevel and **False** otherwise 137 """ 138 139 for handler in get_logger().handlers: 140 if handler.level <= logging_level(TRACE): 141 return True 142 143 return False 144 145 146def escape(message): 147 """ 148 Escapes specific sequences for logging (newlines, tabs, carriage returns). If 149 the input is **bytes** then this converts it to **unicode** under python 3.x. 150 151 :param str message: string to be escaped 152 153 :returns: str that is escaped 154 """ 155 156 if stem.prereq.is_python_3(): 157 message = stem.util.str_tools._to_unicode(message) 158 159 for pattern, replacement in (('\n', '\\n'), ('\r', '\\r'), ('\t', '\\t')): 160 message = message.replace(pattern, replacement) 161 162 return message 163 164 165def log(runlevel, message): 166 """ 167 Logs a message at the given runlevel. 168 169 :param stem.util.log.Runlevel runlevel: runlevel to log the message at, logging is skipped if **None** 170 :param str message: message to be logged 171 """ 172 173 if runlevel: 174 LOGGER.log(LOG_VALUES[runlevel], message) 175 176 177def log_once(message_id, runlevel, message): 178 """ 179 Logs a message at the given runlevel. If a message with this ID has already 180 been logged then this is a no-op. 181 182 :param str message_id: unique message identifier to deduplicate on 183 :param stem.util.log.Runlevel runlevel: runlevel to log the message at, logging is skipped if **None** 184 :param str message: message to be logged 185 186 :returns: **True** if we log the message, **False** otherwise 187 """ 188 189 if not runlevel or message_id in DEDUPLICATION_MESSAGE_IDS: 190 return False 191 else: 192 DEDUPLICATION_MESSAGE_IDS.add(message_id) 193 log(runlevel, message) 194 195# shorter aliases for logging at a runlevel 196 197 198def trace(message): 199 log(Runlevel.TRACE, message) 200 201 202def debug(message): 203 log(Runlevel.DEBUG, message) 204 205 206def info(message): 207 log(Runlevel.INFO, message) 208 209 210def notice(message): 211 log(Runlevel.NOTICE, message) 212 213 214def warn(message): 215 log(Runlevel.WARN, message) 216 217 218def error(message): 219 log(Runlevel.ERROR, message) 220 221 222class LogBuffer(logging.Handler): 223 """ 224 Basic log handler that listens for stem events and stores them so they can be 225 read later. Log entries are cleared as they are read. 226 227 .. versionchanged:: 1.4.0 228 Added the yield_records argument. 229 230 .. deprecated:: 1.8.0 231 This will be dropped in Stem 2.x. Use python's logging.BufferingHandler instead. 232 """ 233 234 def __init__(self, runlevel, yield_records = False): 235 # TODO: At least in python 2.6 logging.Handler has a bug in that it doesn't 236 # extend object, causing our super() call to fail. When we drop python 2.6 237 # support we should switch back to using super() instead. 238 # 239 # super(LogBuffer, self).__init__(level = logging_level(runlevel)) 240 241 logging.Handler.__init__(self, level = logging_level(runlevel)) 242 243 self.formatter = FORMATTER 244 self._buffer = [] 245 self._yield_records = yield_records 246 247 def is_empty(self): 248 return not bool(self._buffer) 249 250 def __iter__(self): 251 while self._buffer: 252 record = self._buffer.pop(0) 253 yield record if self._yield_records else self.formatter.format(record) 254 255 def emit(self, record): 256 self._buffer.append(record) 257 258 259class _StdoutLogger(logging.Handler): 260 def __init__(self, runlevel): 261 logging.Handler.__init__(self, level = logging_level(runlevel)) 262 263 self.formatter = logging.Formatter( 264 fmt = '%(asctime)s [%(levelname)s] %(message)s', 265 datefmt = '%m/%d/%Y %H:%M:%S') 266 267 def emit(self, record): 268 print(self.formatter.format(record)) 269 270 271def log_to_stdout(runlevel): 272 """ 273 Logs further events to stdout. 274 275 :param stem.util.log.Runlevel runlevel: minimum runlevel a message needs to be to be logged 276 """ 277 278 get_logger().addHandler(_StdoutLogger(runlevel)) 279