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