| 1 | #!/usr/bin/env python
|
|---|
| 2 | #
|
|---|
| 3 | # Copyright 2001-2013 by Vinay Sajip. All Rights Reserved.
|
|---|
| 4 | #
|
|---|
| 5 | # Permission to use, copy, modify, and distribute this software and its
|
|---|
| 6 | # documentation for any purpose and without fee is hereby granted,
|
|---|
| 7 | # provided that the above copyright notice appear in all copies and that
|
|---|
| 8 | # both that copyright notice and this permission notice appear in
|
|---|
| 9 | # supporting documentation, and that the name of Vinay Sajip
|
|---|
| 10 | # not be used in advertising or publicity pertaining to distribution
|
|---|
| 11 | # of the software without specific, written prior permission.
|
|---|
| 12 | # VINAY SAJIP DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE, INCLUDING
|
|---|
| 13 | # ALL IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL
|
|---|
| 14 | # VINAY SAJIP BE LIABLE FOR ANY SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR
|
|---|
| 15 | # ANY DAMAGES WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER
|
|---|
| 16 | # IN AN ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT
|
|---|
| 17 | # OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
|
|---|
| 18 |
|
|---|
| 19 | """Test harness for the logging module. Run all tests.
|
|---|
| 20 |
|
|---|
| 21 | Copyright (C) 2001-2013 Vinay Sajip. All Rights Reserved.
|
|---|
| 22 | """
|
|---|
| 23 |
|
|---|
| 24 | import logging
|
|---|
| 25 | import logging.handlers
|
|---|
| 26 | import logging.config
|
|---|
| 27 |
|
|---|
| 28 | import codecs
|
|---|
| 29 | import cPickle
|
|---|
| 30 | import cStringIO
|
|---|
| 31 | import gc
|
|---|
| 32 | import json
|
|---|
| 33 | import os
|
|---|
| 34 | import random
|
|---|
| 35 | import re
|
|---|
| 36 | import select
|
|---|
| 37 | import socket
|
|---|
| 38 | from SocketServer import ThreadingTCPServer, StreamRequestHandler
|
|---|
| 39 | import struct
|
|---|
| 40 | import sys
|
|---|
| 41 | import tempfile
|
|---|
| 42 | from test.test_support import captured_stdout, run_with_locale, run_unittest
|
|---|
| 43 | import textwrap
|
|---|
| 44 | import time
|
|---|
| 45 | import unittest
|
|---|
| 46 | import warnings
|
|---|
| 47 | import weakref
|
|---|
| 48 | try:
|
|---|
| 49 | import threading
|
|---|
| 50 | except ImportError:
|
|---|
| 51 | threading = None
|
|---|
| 52 |
|
|---|
| 53 | class BaseTest(unittest.TestCase):
|
|---|
| 54 |
|
|---|
| 55 | """Base class for logging tests."""
|
|---|
| 56 |
|
|---|
| 57 | log_format = "%(name)s -> %(levelname)s: %(message)s"
|
|---|
| 58 | expected_log_pat = r"^([\w.]+) -> ([\w]+): ([\d]+)$"
|
|---|
| 59 | message_num = 0
|
|---|
| 60 |
|
|---|
| 61 | def setUp(self):
|
|---|
| 62 | """Setup the default logging stream to an internal StringIO instance,
|
|---|
| 63 | so that we can examine log output as we want."""
|
|---|
| 64 | logger_dict = logging.getLogger().manager.loggerDict
|
|---|
| 65 | logging._acquireLock()
|
|---|
| 66 | try:
|
|---|
| 67 | self.saved_handlers = logging._handlers.copy()
|
|---|
| 68 | self.saved_handler_list = logging._handlerList[:]
|
|---|
| 69 | self.saved_loggers = logger_dict.copy()
|
|---|
| 70 | self.saved_level_names = logging._levelNames.copy()
|
|---|
| 71 | finally:
|
|---|
| 72 | logging._releaseLock()
|
|---|
| 73 |
|
|---|
| 74 | # Set two unused loggers: one non-ASCII and one Unicode.
|
|---|
| 75 | # This is to test correct operation when sorting existing
|
|---|
| 76 | # loggers in the configuration code. See issue 8201.
|
|---|
| 77 | logging.getLogger("\xab\xd7\xbb")
|
|---|
| 78 | logging.getLogger(u"\u013f\u00d6\u0047")
|
|---|
| 79 |
|
|---|
| 80 | self.root_logger = logging.getLogger("")
|
|---|
| 81 | self.original_logging_level = self.root_logger.getEffectiveLevel()
|
|---|
| 82 |
|
|---|
| 83 | self.stream = cStringIO.StringIO()
|
|---|
| 84 | self.root_logger.setLevel(logging.DEBUG)
|
|---|
| 85 | self.root_hdlr = logging.StreamHandler(self.stream)
|
|---|
| 86 | self.root_formatter = logging.Formatter(self.log_format)
|
|---|
| 87 | self.root_hdlr.setFormatter(self.root_formatter)
|
|---|
| 88 | self.root_logger.addHandler(self.root_hdlr)
|
|---|
| 89 |
|
|---|
| 90 | def tearDown(self):
|
|---|
| 91 | """Remove our logging stream, and restore the original logging
|
|---|
| 92 | level."""
|
|---|
| 93 | self.stream.close()
|
|---|
| 94 | self.root_logger.removeHandler(self.root_hdlr)
|
|---|
| 95 | while self.root_logger.handlers:
|
|---|
| 96 | h = self.root_logger.handlers[0]
|
|---|
| 97 | self.root_logger.removeHandler(h)
|
|---|
| 98 | h.close()
|
|---|
| 99 | self.root_logger.setLevel(self.original_logging_level)
|
|---|
| 100 | logging._acquireLock()
|
|---|
| 101 | try:
|
|---|
| 102 | logging._levelNames.clear()
|
|---|
| 103 | logging._levelNames.update(self.saved_level_names)
|
|---|
| 104 | logging._handlers.clear()
|
|---|
| 105 | logging._handlers.update(self.saved_handlers)
|
|---|
| 106 | logging._handlerList[:] = self.saved_handler_list
|
|---|
| 107 | loggerDict = logging.getLogger().manager.loggerDict
|
|---|
| 108 | loggerDict.clear()
|
|---|
| 109 | loggerDict.update(self.saved_loggers)
|
|---|
| 110 | finally:
|
|---|
| 111 | logging._releaseLock()
|
|---|
| 112 |
|
|---|
| 113 | def assert_log_lines(self, expected_values, stream=None):
|
|---|
| 114 | """Match the collected log lines against the regular expression
|
|---|
| 115 | self.expected_log_pat, and compare the extracted group values to
|
|---|
| 116 | the expected_values list of tuples."""
|
|---|
| 117 | stream = stream or self.stream
|
|---|
| 118 | pat = re.compile(self.expected_log_pat)
|
|---|
| 119 | try:
|
|---|
| 120 | stream.reset()
|
|---|
| 121 | actual_lines = stream.readlines()
|
|---|
| 122 | except AttributeError:
|
|---|
| 123 | # StringIO.StringIO lacks a reset() method.
|
|---|
| 124 | actual_lines = stream.getvalue().splitlines()
|
|---|
| 125 | self.assertEqual(len(actual_lines), len(expected_values))
|
|---|
| 126 | for actual, expected in zip(actual_lines, expected_values):
|
|---|
| 127 | match = pat.search(actual)
|
|---|
| 128 | if not match:
|
|---|
| 129 | self.fail("Log line does not match expected pattern:\n" +
|
|---|
| 130 | actual)
|
|---|
| 131 | self.assertEqual(tuple(match.groups()), expected)
|
|---|
| 132 | s = stream.read()
|
|---|
| 133 | if s:
|
|---|
| 134 | self.fail("Remaining output at end of log stream:\n" + s)
|
|---|
| 135 |
|
|---|
| 136 | def next_message(self):
|
|---|
| 137 | """Generate a message consisting solely of an auto-incrementing
|
|---|
| 138 | integer."""
|
|---|
| 139 | self.message_num += 1
|
|---|
| 140 | return "%d" % self.message_num
|
|---|
| 141 |
|
|---|
| 142 |
|
|---|
| 143 | class BuiltinLevelsTest(BaseTest):
|
|---|
| 144 | """Test builtin levels and their inheritance."""
|
|---|
| 145 |
|
|---|
| 146 | def test_flat(self):
|
|---|
| 147 | #Logging levels in a flat logger namespace.
|
|---|
| 148 | m = self.next_message
|
|---|
| 149 |
|
|---|
| 150 | ERR = logging.getLogger("ERR")
|
|---|
| 151 | ERR.setLevel(logging.ERROR)
|
|---|
| 152 | INF = logging.getLogger("INF")
|
|---|
| 153 | INF.setLevel(logging.INFO)
|
|---|
| 154 | DEB = logging.getLogger("DEB")
|
|---|
| 155 | DEB.setLevel(logging.DEBUG)
|
|---|
| 156 |
|
|---|
| 157 | # These should log.
|
|---|
| 158 | ERR.log(logging.CRITICAL, m())
|
|---|
| 159 | ERR.error(m())
|
|---|
| 160 |
|
|---|
| 161 | INF.log(logging.CRITICAL, m())
|
|---|
| 162 | INF.error(m())
|
|---|
| 163 | INF.warn(m())
|
|---|
| 164 | INF.info(m())
|
|---|
| 165 |
|
|---|
| 166 | DEB.log(logging.CRITICAL, m())
|
|---|
| 167 | DEB.error(m())
|
|---|
| 168 | DEB.warn (m())
|
|---|
| 169 | DEB.info (m())
|
|---|
| 170 | DEB.debug(m())
|
|---|
| 171 |
|
|---|
| 172 | # These should not log.
|
|---|
| 173 | ERR.warn(m())
|
|---|
| 174 | ERR.info(m())
|
|---|
| 175 | ERR.debug(m())
|
|---|
| 176 |
|
|---|
| 177 | INF.debug(m())
|
|---|
| 178 |
|
|---|
| 179 | self.assert_log_lines([
|
|---|
| 180 | ('ERR', 'CRITICAL', '1'),
|
|---|
| 181 | ('ERR', 'ERROR', '2'),
|
|---|
| 182 | ('INF', 'CRITICAL', '3'),
|
|---|
| 183 | ('INF', 'ERROR', '4'),
|
|---|
| 184 | ('INF', 'WARNING', '5'),
|
|---|
| 185 | ('INF', 'INFO', '6'),
|
|---|
| 186 | ('DEB', 'CRITICAL', '7'),
|
|---|
| 187 | ('DEB', 'ERROR', '8'),
|
|---|
| 188 | ('DEB', 'WARNING', '9'),
|
|---|
| 189 | ('DEB', 'INFO', '10'),
|
|---|
| 190 | ('DEB', 'DEBUG', '11'),
|
|---|
| 191 | ])
|
|---|
| 192 |
|
|---|
| 193 | def test_nested_explicit(self):
|
|---|
| 194 | # Logging levels in a nested namespace, all explicitly set.
|
|---|
| 195 | m = self.next_message
|
|---|
| 196 |
|
|---|
| 197 | INF = logging.getLogger("INF")
|
|---|
| 198 | INF.setLevel(logging.INFO)
|
|---|
| 199 | INF_ERR = logging.getLogger("INF.ERR")
|
|---|
| 200 | INF_ERR.setLevel(logging.ERROR)
|
|---|
| 201 |
|
|---|
| 202 | # These should log.
|
|---|
| 203 | INF_ERR.log(logging.CRITICAL, m())
|
|---|
| 204 | INF_ERR.error(m())
|
|---|
| 205 |
|
|---|
| 206 | # These should not log.
|
|---|
| 207 | INF_ERR.warn(m())
|
|---|
| 208 | INF_ERR.info(m())
|
|---|
| 209 | INF_ERR.debug(m())
|
|---|
| 210 |
|
|---|
| 211 | self.assert_log_lines([
|
|---|
| 212 | ('INF.ERR', 'CRITICAL', '1'),
|
|---|
| 213 | ('INF.ERR', 'ERROR', '2'),
|
|---|
| 214 | ])
|
|---|
| 215 |
|
|---|
| 216 | def test_nested_inherited(self):
|
|---|
| 217 | #Logging levels in a nested namespace, inherited from parent loggers.
|
|---|
| 218 | m = self.next_message
|
|---|
| 219 |
|
|---|
| 220 | INF = logging.getLogger("INF")
|
|---|
| 221 | INF.setLevel(logging.INFO)
|
|---|
| 222 | INF_ERR = logging.getLogger("INF.ERR")
|
|---|
| 223 | INF_ERR.setLevel(logging.ERROR)
|
|---|
| 224 | INF_UNDEF = logging.getLogger("INF.UNDEF")
|
|---|
| 225 | INF_ERR_UNDEF = logging.getLogger("INF.ERR.UNDEF")
|
|---|
| 226 | UNDEF = logging.getLogger("UNDEF")
|
|---|
| 227 |
|
|---|
| 228 | # These should log.
|
|---|
| 229 | INF_UNDEF.log(logging.CRITICAL, m())
|
|---|
| 230 | INF_UNDEF.error(m())
|
|---|
| 231 | INF_UNDEF.warn(m())
|
|---|
| 232 | INF_UNDEF.info(m())
|
|---|
| 233 | INF_ERR_UNDEF.log(logging.CRITICAL, m())
|
|---|
| 234 | INF_ERR_UNDEF.error(m())
|
|---|
| 235 |
|
|---|
| 236 | # These should not log.
|
|---|
| 237 | INF_UNDEF.debug(m())
|
|---|
| 238 | INF_ERR_UNDEF.warn(m())
|
|---|
| 239 | INF_ERR_UNDEF.info(m())
|
|---|
| 240 | INF_ERR_UNDEF.debug(m())
|
|---|
| 241 |
|
|---|
| 242 | self.assert_log_lines([
|
|---|
| 243 | ('INF.UNDEF', 'CRITICAL', '1'),
|
|---|
| 244 | ('INF.UNDEF', 'ERROR', '2'),
|
|---|
| 245 | ('INF.UNDEF', 'WARNING', '3'),
|
|---|
| 246 | ('INF.UNDEF', 'INFO', '4'),
|
|---|
| 247 | ('INF.ERR.UNDEF', 'CRITICAL', '5'),
|
|---|
| 248 | ('INF.ERR.UNDEF', 'ERROR', '6'),
|
|---|
| 249 | ])
|
|---|
| 250 |
|
|---|
| 251 | def test_nested_with_virtual_parent(self):
|
|---|
| 252 | # Logging levels when some parent does not exist yet.
|
|---|
| 253 | m = self.next_message
|
|---|
| 254 |
|
|---|
| 255 | INF = logging.getLogger("INF")
|
|---|
| 256 | GRANDCHILD = logging.getLogger("INF.BADPARENT.UNDEF")
|
|---|
| 257 | CHILD = logging.getLogger("INF.BADPARENT")
|
|---|
| 258 | INF.setLevel(logging.INFO)
|
|---|
| 259 |
|
|---|
| 260 | # These should log.
|
|---|
| 261 | GRANDCHILD.log(logging.FATAL, m())
|
|---|
| 262 | GRANDCHILD.info(m())
|
|---|
| 263 | CHILD.log(logging.FATAL, m())
|
|---|
| 264 | CHILD.info(m())
|
|---|
| 265 |
|
|---|
| 266 | # These should not log.
|
|---|
| 267 | GRANDCHILD.debug(m())
|
|---|
| 268 | CHILD.debug(m())
|
|---|
| 269 |
|
|---|
| 270 | self.assert_log_lines([
|
|---|
| 271 | ('INF.BADPARENT.UNDEF', 'CRITICAL', '1'),
|
|---|
| 272 | ('INF.BADPARENT.UNDEF', 'INFO', '2'),
|
|---|
| 273 | ('INF.BADPARENT', 'CRITICAL', '3'),
|
|---|
| 274 | ('INF.BADPARENT', 'INFO', '4'),
|
|---|
| 275 | ])
|
|---|
| 276 |
|
|---|
| 277 | def test_invalid_name(self):
|
|---|
| 278 | self.assertRaises(TypeError, logging.getLogger, any)
|
|---|
| 279 |
|
|---|
| 280 | class BasicFilterTest(BaseTest):
|
|---|
| 281 |
|
|---|
| 282 | """Test the bundled Filter class."""
|
|---|
| 283 |
|
|---|
| 284 | def test_filter(self):
|
|---|
| 285 | # Only messages satisfying the specified criteria pass through the
|
|---|
| 286 | # filter.
|
|---|
| 287 | filter_ = logging.Filter("spam.eggs")
|
|---|
| 288 | handler = self.root_logger.handlers[0]
|
|---|
| 289 | try:
|
|---|
| 290 | handler.addFilter(filter_)
|
|---|
| 291 | spam = logging.getLogger("spam")
|
|---|
| 292 | spam_eggs = logging.getLogger("spam.eggs")
|
|---|
| 293 | spam_eggs_fish = logging.getLogger("spam.eggs.fish")
|
|---|
| 294 | spam_bakedbeans = logging.getLogger("spam.bakedbeans")
|
|---|
| 295 |
|
|---|
| 296 | spam.info(self.next_message())
|
|---|
| 297 | spam_eggs.info(self.next_message()) # Good.
|
|---|
| 298 | spam_eggs_fish.info(self.next_message()) # Good.
|
|---|
| 299 | spam_bakedbeans.info(self.next_message())
|
|---|
| 300 |
|
|---|
| 301 | self.assert_log_lines([
|
|---|
| 302 | ('spam.eggs', 'INFO', '2'),
|
|---|
| 303 | ('spam.eggs.fish', 'INFO', '3'),
|
|---|
| 304 | ])
|
|---|
| 305 | finally:
|
|---|
| 306 | handler.removeFilter(filter_)
|
|---|
| 307 |
|
|---|
| 308 |
|
|---|
| 309 | #
|
|---|
| 310 | # First, we define our levels. There can be as many as you want - the only
|
|---|
| 311 | # limitations are that they should be integers, the lowest should be > 0 and
|
|---|
| 312 | # larger values mean less information being logged. If you need specific
|
|---|
| 313 | # level values which do not fit into these limitations, you can use a
|
|---|
| 314 | # mapping dictionary to convert between your application levels and the
|
|---|
| 315 | # logging system.
|
|---|
| 316 | #
|
|---|
| 317 | SILENT = 120
|
|---|
| 318 | TACITURN = 119
|
|---|
| 319 | TERSE = 118
|
|---|
| 320 | EFFUSIVE = 117
|
|---|
| 321 | SOCIABLE = 116
|
|---|
| 322 | VERBOSE = 115
|
|---|
| 323 | TALKATIVE = 114
|
|---|
| 324 | GARRULOUS = 113
|
|---|
| 325 | CHATTERBOX = 112
|
|---|
| 326 | BORING = 111
|
|---|
| 327 |
|
|---|
| 328 | LEVEL_RANGE = range(BORING, SILENT + 1)
|
|---|
| 329 |
|
|---|
| 330 | #
|
|---|
| 331 | # Next, we define names for our levels. You don't need to do this - in which
|
|---|
| 332 | # case the system will use "Level n" to denote the text for the level.
|
|---|
| 333 | #
|
|---|
| 334 | my_logging_levels = {
|
|---|
| 335 | SILENT : 'Silent',
|
|---|
| 336 | TACITURN : 'Taciturn',
|
|---|
| 337 | TERSE : 'Terse',
|
|---|
| 338 | EFFUSIVE : 'Effusive',
|
|---|
| 339 | SOCIABLE : 'Sociable',
|
|---|
| 340 | VERBOSE : 'Verbose',
|
|---|
| 341 | TALKATIVE : 'Talkative',
|
|---|
| 342 | GARRULOUS : 'Garrulous',
|
|---|
| 343 | CHATTERBOX : 'Chatterbox',
|
|---|
| 344 | BORING : 'Boring',
|
|---|
| 345 | }
|
|---|
| 346 |
|
|---|
| 347 | class GarrulousFilter(logging.Filter):
|
|---|
| 348 |
|
|---|
| 349 | """A filter which blocks garrulous messages."""
|
|---|
| 350 |
|
|---|
| 351 | def filter(self, record):
|
|---|
| 352 | return record.levelno != GARRULOUS
|
|---|
| 353 |
|
|---|
| 354 | class VerySpecificFilter(logging.Filter):
|
|---|
| 355 |
|
|---|
| 356 | """A filter which blocks sociable and taciturn messages."""
|
|---|
| 357 |
|
|---|
| 358 | def filter(self, record):
|
|---|
| 359 | return record.levelno not in [SOCIABLE, TACITURN]
|
|---|
| 360 |
|
|---|
| 361 |
|
|---|
| 362 | class CustomLevelsAndFiltersTest(BaseTest):
|
|---|
| 363 |
|
|---|
| 364 | """Test various filtering possibilities with custom logging levels."""
|
|---|
| 365 |
|
|---|
| 366 | # Skip the logger name group.
|
|---|
| 367 | expected_log_pat = r"^[\w.]+ -> ([\w]+): ([\d]+)$"
|
|---|
| 368 |
|
|---|
| 369 | def setUp(self):
|
|---|
| 370 | BaseTest.setUp(self)
|
|---|
| 371 | for k, v in my_logging_levels.items():
|
|---|
| 372 | logging.addLevelName(k, v)
|
|---|
| 373 |
|
|---|
| 374 | def log_at_all_levels(self, logger):
|
|---|
| 375 | for lvl in LEVEL_RANGE:
|
|---|
| 376 | logger.log(lvl, self.next_message())
|
|---|
| 377 |
|
|---|
| 378 | def test_logger_filter(self):
|
|---|
| 379 | # Filter at logger level.
|
|---|
| 380 | self.root_logger.setLevel(VERBOSE)
|
|---|
| 381 | # Levels >= 'Verbose' are good.
|
|---|
| 382 | self.log_at_all_levels(self.root_logger)
|
|---|
| 383 | self.assert_log_lines([
|
|---|
| 384 | ('Verbose', '5'),
|
|---|
| 385 | ('Sociable', '6'),
|
|---|
| 386 | ('Effusive', '7'),
|
|---|
| 387 | ('Terse', '8'),
|
|---|
| 388 | ('Taciturn', '9'),
|
|---|
| 389 | ('Silent', '10'),
|
|---|
| 390 | ])
|
|---|
| 391 |
|
|---|
| 392 | def test_handler_filter(self):
|
|---|
| 393 | # Filter at handler level.
|
|---|
| 394 | self.root_logger.handlers[0].setLevel(SOCIABLE)
|
|---|
| 395 | try:
|
|---|
| 396 | # Levels >= 'Sociable' are good.
|
|---|
| 397 | self.log_at_all_levels(self.root_logger)
|
|---|
| 398 | self.assert_log_lines([
|
|---|
| 399 | ('Sociable', '6'),
|
|---|
| 400 | ('Effusive', '7'),
|
|---|
| 401 | ('Terse', '8'),
|
|---|
| 402 | ('Taciturn', '9'),
|
|---|
| 403 | ('Silent', '10'),
|
|---|
| 404 | ])
|
|---|
| 405 | finally:
|
|---|
| 406 | self.root_logger.handlers[0].setLevel(logging.NOTSET)
|
|---|
| 407 |
|
|---|
| 408 | def test_specific_filters(self):
|
|---|
| 409 | # Set a specific filter object on the handler, and then add another
|
|---|
| 410 | # filter object on the logger itself.
|
|---|
| 411 | handler = self.root_logger.handlers[0]
|
|---|
| 412 | specific_filter = None
|
|---|
| 413 | garr = GarrulousFilter()
|
|---|
| 414 | handler.addFilter(garr)
|
|---|
| 415 | try:
|
|---|
| 416 | self.log_at_all_levels(self.root_logger)
|
|---|
| 417 | first_lines = [
|
|---|
| 418 | # Notice how 'Garrulous' is missing
|
|---|
| 419 | ('Boring', '1'),
|
|---|
| 420 | ('Chatterbox', '2'),
|
|---|
| 421 | ('Talkative', '4'),
|
|---|
| 422 | ('Verbose', '5'),
|
|---|
| 423 | ('Sociable', '6'),
|
|---|
| 424 | ('Effusive', '7'),
|
|---|
| 425 | ('Terse', '8'),
|
|---|
| 426 | ('Taciturn', '9'),
|
|---|
| 427 | ('Silent', '10'),
|
|---|
| 428 | ]
|
|---|
| 429 | self.assert_log_lines(first_lines)
|
|---|
| 430 |
|
|---|
| 431 | specific_filter = VerySpecificFilter()
|
|---|
| 432 | self.root_logger.addFilter(specific_filter)
|
|---|
| 433 | self.log_at_all_levels(self.root_logger)
|
|---|
| 434 | self.assert_log_lines(first_lines + [
|
|---|
| 435 | # Not only 'Garrulous' is still missing, but also 'Sociable'
|
|---|
| 436 | # and 'Taciturn'
|
|---|
| 437 | ('Boring', '11'),
|
|---|
| 438 | ('Chatterbox', '12'),
|
|---|
| 439 | ('Talkative', '14'),
|
|---|
| 440 | ('Verbose', '15'),
|
|---|
| 441 | ('Effusive', '17'),
|
|---|
| 442 | ('Terse', '18'),
|
|---|
| 443 | ('Silent', '20'),
|
|---|
| 444 | ])
|
|---|
| 445 | finally:
|
|---|
| 446 | if specific_filter:
|
|---|
| 447 | self.root_logger.removeFilter(specific_filter)
|
|---|
| 448 | handler.removeFilter(garr)
|
|---|
| 449 |
|
|---|
| 450 |
|
|---|
| 451 | class MemoryHandlerTest(BaseTest):
|
|---|
| 452 |
|
|---|
| 453 | """Tests for the MemoryHandler."""
|
|---|
| 454 |
|
|---|
| 455 | # Do not bother with a logger name group.
|
|---|
| 456 | expected_log_pat = r"^[\w.]+ -> ([\w]+): ([\d]+)$"
|
|---|
| 457 |
|
|---|
| 458 | def setUp(self):
|
|---|
| 459 | BaseTest.setUp(self)
|
|---|
| 460 | self.mem_hdlr = logging.handlers.MemoryHandler(10, logging.WARNING,
|
|---|
| 461 | self.root_hdlr)
|
|---|
| 462 | self.mem_logger = logging.getLogger('mem')
|
|---|
| 463 | self.mem_logger.propagate = 0
|
|---|
| 464 | self.mem_logger.addHandler(self.mem_hdlr)
|
|---|
| 465 |
|
|---|
| 466 | def tearDown(self):
|
|---|
| 467 | self.mem_hdlr.close()
|
|---|
| 468 | BaseTest.tearDown(self)
|
|---|
| 469 |
|
|---|
| 470 | def test_flush(self):
|
|---|
| 471 | # The memory handler flushes to its target handler based on specific
|
|---|
| 472 | # criteria (message count and message level).
|
|---|
| 473 | self.mem_logger.debug(self.next_message())
|
|---|
| 474 | self.assert_log_lines([])
|
|---|
| 475 | self.mem_logger.info(self.next_message())
|
|---|
| 476 | self.assert_log_lines([])
|
|---|
| 477 | # This will flush because the level is >= logging.WARNING
|
|---|
| 478 | self.mem_logger.warn(self.next_message())
|
|---|
| 479 | lines = [
|
|---|
| 480 | ('DEBUG', '1'),
|
|---|
| 481 | ('INFO', '2'),
|
|---|
| 482 | ('WARNING', '3'),
|
|---|
| 483 | ]
|
|---|
| 484 | self.assert_log_lines(lines)
|
|---|
| 485 | for n in (4, 14):
|
|---|
| 486 | for i in range(9):
|
|---|
| 487 | self.mem_logger.debug(self.next_message())
|
|---|
| 488 | self.assert_log_lines(lines)
|
|---|
| 489 | # This will flush because it's the 10th message since the last
|
|---|
| 490 | # flush.
|
|---|
| 491 | self.mem_logger.debug(self.next_message())
|
|---|
| 492 | lines = lines + [('DEBUG', str(i)) for i in range(n, n + 10)]
|
|---|
| 493 | self.assert_log_lines(lines)
|
|---|
| 494 |
|
|---|
| 495 | self.mem_logger.debug(self.next_message())
|
|---|
| 496 | self.assert_log_lines(lines)
|
|---|
| 497 |
|
|---|
| 498 |
|
|---|
| 499 | class ExceptionFormatter(logging.Formatter):
|
|---|
| 500 | """A special exception formatter."""
|
|---|
| 501 | def formatException(self, ei):
|
|---|
| 502 | return "Got a [%s]" % ei[0].__name__
|
|---|
| 503 |
|
|---|
| 504 |
|
|---|
| 505 | class ConfigFileTest(BaseTest):
|
|---|
| 506 |
|
|---|
| 507 | """Reading logging config from a .ini-style config file."""
|
|---|
| 508 |
|
|---|
| 509 | expected_log_pat = r"^([\w]+) \+\+ ([\w]+)$"
|
|---|
| 510 |
|
|---|
| 511 | # config0 is a standard configuration.
|
|---|
| 512 | config0 = """
|
|---|
| 513 | [loggers]
|
|---|
| 514 | keys=root
|
|---|
| 515 |
|
|---|
| 516 | [handlers]
|
|---|
| 517 | keys=hand1
|
|---|
| 518 |
|
|---|
| 519 | [formatters]
|
|---|
| 520 | keys=form1
|
|---|
| 521 |
|
|---|
| 522 | [logger_root]
|
|---|
| 523 | level=WARNING
|
|---|
| 524 | handlers=hand1
|
|---|
| 525 |
|
|---|
| 526 | [handler_hand1]
|
|---|
| 527 | class=StreamHandler
|
|---|
| 528 | level=NOTSET
|
|---|
| 529 | formatter=form1
|
|---|
| 530 | args=(sys.stdout,)
|
|---|
| 531 |
|
|---|
| 532 | [formatter_form1]
|
|---|
| 533 | format=%(levelname)s ++ %(message)s
|
|---|
| 534 | datefmt=
|
|---|
| 535 | """
|
|---|
| 536 |
|
|---|
| 537 | # config1 adds a little to the standard configuration.
|
|---|
| 538 | config1 = """
|
|---|
| 539 | [loggers]
|
|---|
| 540 | keys=root,parser
|
|---|
| 541 |
|
|---|
| 542 | [handlers]
|
|---|
| 543 | keys=hand1
|
|---|
| 544 |
|
|---|
| 545 | [formatters]
|
|---|
| 546 | keys=form1
|
|---|
| 547 |
|
|---|
| 548 | [logger_root]
|
|---|
| 549 | level=WARNING
|
|---|
| 550 | handlers=
|
|---|
| 551 |
|
|---|
| 552 | [logger_parser]
|
|---|
| 553 | level=DEBUG
|
|---|
| 554 | handlers=hand1
|
|---|
| 555 | propagate=1
|
|---|
| 556 | qualname=compiler.parser
|
|---|
| 557 |
|
|---|
| 558 | [handler_hand1]
|
|---|
| 559 | class=StreamHandler
|
|---|
| 560 | level=NOTSET
|
|---|
| 561 | formatter=form1
|
|---|
| 562 | args=(sys.stdout,)
|
|---|
| 563 |
|
|---|
| 564 | [formatter_form1]
|
|---|
| 565 | format=%(levelname)s ++ %(message)s
|
|---|
| 566 | datefmt=
|
|---|
| 567 | """
|
|---|
| 568 |
|
|---|
| 569 | # config1a moves the handler to the root.
|
|---|
| 570 | config1a = """
|
|---|
| 571 | [loggers]
|
|---|
| 572 | keys=root,parser
|
|---|
| 573 |
|
|---|
| 574 | [handlers]
|
|---|
| 575 | keys=hand1
|
|---|
| 576 |
|
|---|
| 577 | [formatters]
|
|---|
| 578 | keys=form1
|
|---|
| 579 |
|
|---|
| 580 | [logger_root]
|
|---|
| 581 | level=WARNING
|
|---|
| 582 | handlers=hand1
|
|---|
| 583 |
|
|---|
| 584 | [logger_parser]
|
|---|
| 585 | level=DEBUG
|
|---|
| 586 | handlers=
|
|---|
| 587 | propagate=1
|
|---|
| 588 | qualname=compiler.parser
|
|---|
| 589 |
|
|---|
| 590 | [handler_hand1]
|
|---|
| 591 | class=StreamHandler
|
|---|
| 592 | level=NOTSET
|
|---|
| 593 | formatter=form1
|
|---|
| 594 | args=(sys.stdout,)
|
|---|
| 595 |
|
|---|
| 596 | [formatter_form1]
|
|---|
| 597 | format=%(levelname)s ++ %(message)s
|
|---|
| 598 | datefmt=
|
|---|
| 599 | """
|
|---|
| 600 |
|
|---|
| 601 | # config2 has a subtle configuration error that should be reported
|
|---|
| 602 | config2 = config1.replace("sys.stdout", "sys.stbout")
|
|---|
| 603 |
|
|---|
| 604 | # config3 has a less subtle configuration error
|
|---|
| 605 | config3 = config1.replace("formatter=form1", "formatter=misspelled_name")
|
|---|
| 606 |
|
|---|
| 607 | # config4 specifies a custom formatter class to be loaded
|
|---|
| 608 | config4 = """
|
|---|
| 609 | [loggers]
|
|---|
| 610 | keys=root
|
|---|
| 611 |
|
|---|
| 612 | [handlers]
|
|---|
| 613 | keys=hand1
|
|---|
| 614 |
|
|---|
| 615 | [formatters]
|
|---|
| 616 | keys=form1
|
|---|
| 617 |
|
|---|
| 618 | [logger_root]
|
|---|
| 619 | level=NOTSET
|
|---|
| 620 | handlers=hand1
|
|---|
| 621 |
|
|---|
| 622 | [handler_hand1]
|
|---|
| 623 | class=StreamHandler
|
|---|
| 624 | level=NOTSET
|
|---|
| 625 | formatter=form1
|
|---|
| 626 | args=(sys.stdout,)
|
|---|
| 627 |
|
|---|
| 628 | [formatter_form1]
|
|---|
| 629 | class=""" + __name__ + """.ExceptionFormatter
|
|---|
| 630 | format=%(levelname)s:%(name)s:%(message)s
|
|---|
| 631 | datefmt=
|
|---|
| 632 | """
|
|---|
| 633 |
|
|---|
| 634 | # config5 specifies a custom handler class to be loaded
|
|---|
| 635 | config5 = config1.replace('class=StreamHandler', 'class=logging.StreamHandler')
|
|---|
| 636 |
|
|---|
| 637 | # config6 uses ', ' delimiters in the handlers and formatters sections
|
|---|
| 638 | config6 = """
|
|---|
| 639 | [loggers]
|
|---|
| 640 | keys=root,parser
|
|---|
| 641 |
|
|---|
| 642 | [handlers]
|
|---|
| 643 | keys=hand1, hand2
|
|---|
| 644 |
|
|---|
| 645 | [formatters]
|
|---|
| 646 | keys=form1, form2
|
|---|
| 647 |
|
|---|
| 648 | [logger_root]
|
|---|
| 649 | level=WARNING
|
|---|
| 650 | handlers=
|
|---|
| 651 |
|
|---|
| 652 | [logger_parser]
|
|---|
| 653 | level=DEBUG
|
|---|
| 654 | handlers=hand1
|
|---|
| 655 | propagate=1
|
|---|
| 656 | qualname=compiler.parser
|
|---|
| 657 |
|
|---|
| 658 | [handler_hand1]
|
|---|
| 659 | class=StreamHandler
|
|---|
| 660 | level=NOTSET
|
|---|
| 661 | formatter=form1
|
|---|
| 662 | args=(sys.stdout,)
|
|---|
| 663 |
|
|---|
| 664 | [handler_hand2]
|
|---|
| 665 | class=StreamHandler
|
|---|
| 666 | level=NOTSET
|
|---|
| 667 | formatter=form1
|
|---|
| 668 | args=(sys.stderr,)
|
|---|
| 669 |
|
|---|
| 670 | [formatter_form1]
|
|---|
| 671 | format=%(levelname)s ++ %(message)s
|
|---|
| 672 | datefmt=
|
|---|
| 673 |
|
|---|
| 674 | [formatter_form2]
|
|---|
| 675 | format=%(message)s
|
|---|
| 676 | datefmt=
|
|---|
| 677 | """
|
|---|
| 678 |
|
|---|
| 679 | # config7 adds a compiler logger.
|
|---|
| 680 | config7 = """
|
|---|
| 681 | [loggers]
|
|---|
| 682 | keys=root,parser,compiler
|
|---|
| 683 |
|
|---|
| 684 | [handlers]
|
|---|
| 685 | keys=hand1
|
|---|
| 686 |
|
|---|
| 687 | [formatters]
|
|---|
| 688 | keys=form1
|
|---|
| 689 |
|
|---|
| 690 | [logger_root]
|
|---|
| 691 | level=WARNING
|
|---|
| 692 | handlers=hand1
|
|---|
| 693 |
|
|---|
| 694 | [logger_compiler]
|
|---|
| 695 | level=DEBUG
|
|---|
| 696 | handlers=
|
|---|
| 697 | propagate=1
|
|---|
| 698 | qualname=compiler
|
|---|
| 699 |
|
|---|
| 700 | [logger_parser]
|
|---|
| 701 | level=DEBUG
|
|---|
| 702 | handlers=
|
|---|
| 703 | propagate=1
|
|---|
| 704 | qualname=compiler.parser
|
|---|
| 705 |
|
|---|
| 706 | [handler_hand1]
|
|---|
| 707 | class=StreamHandler
|
|---|
| 708 | level=NOTSET
|
|---|
| 709 | formatter=form1
|
|---|
| 710 | args=(sys.stdout,)
|
|---|
| 711 |
|
|---|
| 712 | [formatter_form1]
|
|---|
| 713 | format=%(levelname)s ++ %(message)s
|
|---|
| 714 | datefmt=
|
|---|
| 715 | """
|
|---|
| 716 |
|
|---|
| 717 | disable_test = """
|
|---|
| 718 | [loggers]
|
|---|
| 719 | keys=root
|
|---|
| 720 |
|
|---|
| 721 | [handlers]
|
|---|
| 722 | keys=screen
|
|---|
| 723 |
|
|---|
| 724 | [formatters]
|
|---|
| 725 | keys=
|
|---|
| 726 |
|
|---|
| 727 | [logger_root]
|
|---|
| 728 | level=DEBUG
|
|---|
| 729 | handlers=screen
|
|---|
| 730 |
|
|---|
| 731 | [handler_screen]
|
|---|
| 732 | level=DEBUG
|
|---|
| 733 | class=StreamHandler
|
|---|
| 734 | args=(sys.stdout,)
|
|---|
| 735 | formatter=
|
|---|
| 736 | """
|
|---|
| 737 |
|
|---|
| 738 | def apply_config(self, conf, **kwargs):
|
|---|
| 739 | file = cStringIO.StringIO(textwrap.dedent(conf))
|
|---|
| 740 | logging.config.fileConfig(file, **kwargs)
|
|---|
| 741 |
|
|---|
| 742 | def test_config0_ok(self):
|
|---|
| 743 | # A simple config file which overrides the default settings.
|
|---|
| 744 | with captured_stdout() as output:
|
|---|
| 745 | self.apply_config(self.config0)
|
|---|
| 746 | logger = logging.getLogger()
|
|---|
| 747 | # Won't output anything
|
|---|
| 748 | logger.info(self.next_message())
|
|---|
| 749 | # Outputs a message
|
|---|
| 750 | logger.error(self.next_message())
|
|---|
| 751 | self.assert_log_lines([
|
|---|
| 752 | ('ERROR', '2'),
|
|---|
| 753 | ], stream=output)
|
|---|
| 754 | # Original logger output is empty.
|
|---|
| 755 | self.assert_log_lines([])
|
|---|
| 756 |
|
|---|
| 757 | def test_config1_ok(self, config=config1):
|
|---|
| 758 | # A config file defining a sub-parser as well.
|
|---|
| 759 | with captured_stdout() as output:
|
|---|
| 760 | self.apply_config(config)
|
|---|
| 761 | logger = logging.getLogger("compiler.parser")
|
|---|
| 762 | # Both will output a message
|
|---|
| 763 | logger.info(self.next_message())
|
|---|
| 764 | logger.error(self.next_message())
|
|---|
| 765 | self.assert_log_lines([
|
|---|
| 766 | ('INFO', '1'),
|
|---|
| 767 | ('ERROR', '2'),
|
|---|
| 768 | ], stream=output)
|
|---|
| 769 | # Original logger output is empty.
|
|---|
| 770 | self.assert_log_lines([])
|
|---|
| 771 |
|
|---|
| 772 | def test_config2_failure(self):
|
|---|
| 773 | # A simple config file which overrides the default settings.
|
|---|
| 774 | self.assertRaises(StandardError, self.apply_config, self.config2)
|
|---|
| 775 |
|
|---|
| 776 | def test_config3_failure(self):
|
|---|
| 777 | # A simple config file which overrides the default settings.
|
|---|
| 778 | self.assertRaises(StandardError, self.apply_config, self.config3)
|
|---|
| 779 |
|
|---|
| 780 | def test_config4_ok(self):
|
|---|
| 781 | # A config file specifying a custom formatter class.
|
|---|
| 782 | with captured_stdout() as output:
|
|---|
| 783 | self.apply_config(self.config4)
|
|---|
| 784 | logger = logging.getLogger()
|
|---|
| 785 | try:
|
|---|
| 786 | raise RuntimeError()
|
|---|
| 787 | except RuntimeError:
|
|---|
| 788 | logging.exception("just testing")
|
|---|
| 789 | sys.stdout.seek(0)
|
|---|
| 790 | self.assertEqual(output.getvalue(),
|
|---|
| 791 | "ERROR:root:just testing\nGot a [RuntimeError]\n")
|
|---|
| 792 | # Original logger output is empty
|
|---|
| 793 | self.assert_log_lines([])
|
|---|
| 794 |
|
|---|
| 795 | def test_config5_ok(self):
|
|---|
| 796 | self.test_config1_ok(config=self.config5)
|
|---|
| 797 |
|
|---|
| 798 | def test_config6_ok(self):
|
|---|
| 799 | self.test_config1_ok(config=self.config6)
|
|---|
| 800 |
|
|---|
| 801 | def test_config7_ok(self):
|
|---|
| 802 | with captured_stdout() as output:
|
|---|
| 803 | self.apply_config(self.config1a)
|
|---|
| 804 | logger = logging.getLogger("compiler.parser")
|
|---|
| 805 | # See issue #11424. compiler-hyphenated sorts
|
|---|
| 806 | # between compiler and compiler.xyz and this
|
|---|
| 807 | # was preventing compiler.xyz from being included
|
|---|
| 808 | # in the child loggers of compiler because of an
|
|---|
| 809 | # overzealous loop termination condition.
|
|---|
| 810 | hyphenated = logging.getLogger('compiler-hyphenated')
|
|---|
| 811 | # All will output a message
|
|---|
| 812 | logger.info(self.next_message())
|
|---|
| 813 | logger.error(self.next_message())
|
|---|
| 814 | hyphenated.critical(self.next_message())
|
|---|
| 815 | self.assert_log_lines([
|
|---|
| 816 | ('INFO', '1'),
|
|---|
| 817 | ('ERROR', '2'),
|
|---|
| 818 | ('CRITICAL', '3'),
|
|---|
| 819 | ], stream=output)
|
|---|
| 820 | # Original logger output is empty.
|
|---|
| 821 | self.assert_log_lines([])
|
|---|
| 822 | with captured_stdout() as output:
|
|---|
| 823 | self.apply_config(self.config7)
|
|---|
| 824 | logger = logging.getLogger("compiler.parser")
|
|---|
| 825 | self.assertFalse(logger.disabled)
|
|---|
| 826 | # Both will output a message
|
|---|
| 827 | logger.info(self.next_message())
|
|---|
| 828 | logger.error(self.next_message())
|
|---|
| 829 | logger = logging.getLogger("compiler.lexer")
|
|---|
| 830 | # Both will output a message
|
|---|
| 831 | logger.info(self.next_message())
|
|---|
| 832 | logger.error(self.next_message())
|
|---|
| 833 | # Will not appear
|
|---|
| 834 | hyphenated.critical(self.next_message())
|
|---|
| 835 | self.assert_log_lines([
|
|---|
| 836 | ('INFO', '4'),
|
|---|
| 837 | ('ERROR', '5'),
|
|---|
| 838 | ('INFO', '6'),
|
|---|
| 839 | ('ERROR', '7'),
|
|---|
| 840 | ], stream=output)
|
|---|
| 841 | # Original logger output is empty.
|
|---|
| 842 | self.assert_log_lines([])
|
|---|
| 843 |
|
|---|
| 844 | def test_logger_disabling(self):
|
|---|
| 845 | self.apply_config(self.disable_test)
|
|---|
| 846 | logger = logging.getLogger('foo')
|
|---|
| 847 | self.assertFalse(logger.disabled)
|
|---|
| 848 | self.apply_config(self.disable_test)
|
|---|
| 849 | self.assertTrue(logger.disabled)
|
|---|
| 850 | self.apply_config(self.disable_test, disable_existing_loggers=False)
|
|---|
| 851 | self.assertFalse(logger.disabled)
|
|---|
| 852 |
|
|---|
| 853 | class LogRecordStreamHandler(StreamRequestHandler):
|
|---|
| 854 |
|
|---|
| 855 | """Handler for a streaming logging request. It saves the log message in the
|
|---|
| 856 | TCP server's 'log_output' attribute."""
|
|---|
| 857 |
|
|---|
| 858 | TCP_LOG_END = "!!!END!!!"
|
|---|
| 859 |
|
|---|
| 860 | def handle(self):
|
|---|
| 861 | """Handle multiple requests - each expected to be of 4-byte length,
|
|---|
| 862 | followed by the LogRecord in pickle format. Logs the record
|
|---|
| 863 | according to whatever policy is configured locally."""
|
|---|
| 864 | while True:
|
|---|
| 865 | chunk = self.connection.recv(4)
|
|---|
| 866 | if len(chunk) < 4:
|
|---|
| 867 | break
|
|---|
| 868 | slen = struct.unpack(">L", chunk)[0]
|
|---|
| 869 | chunk = self.connection.recv(slen)
|
|---|
| 870 | while len(chunk) < slen:
|
|---|
| 871 | chunk = chunk + self.connection.recv(slen - len(chunk))
|
|---|
| 872 | obj = self.unpickle(chunk)
|
|---|
| 873 | record = logging.makeLogRecord(obj)
|
|---|
| 874 | self.handle_log_record(record)
|
|---|
| 875 |
|
|---|
| 876 | def unpickle(self, data):
|
|---|
| 877 | return cPickle.loads(data)
|
|---|
| 878 |
|
|---|
| 879 | def handle_log_record(self, record):
|
|---|
| 880 | # If the end-of-messages sentinel is seen, tell the server to
|
|---|
| 881 | # terminate.
|
|---|
| 882 | if self.TCP_LOG_END in record.msg:
|
|---|
| 883 | self.server.abort = 1
|
|---|
| 884 | return
|
|---|
| 885 | self.server.log_output += record.msg + "\n"
|
|---|
| 886 |
|
|---|
| 887 |
|
|---|
| 888 | class LogRecordSocketReceiver(ThreadingTCPServer):
|
|---|
| 889 |
|
|---|
| 890 | """A simple-minded TCP socket-based logging receiver suitable for test
|
|---|
| 891 | purposes."""
|
|---|
| 892 |
|
|---|
| 893 | allow_reuse_address = 1
|
|---|
| 894 | log_output = ""
|
|---|
| 895 |
|
|---|
| 896 | def __init__(self, host='localhost',
|
|---|
| 897 | port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
|
|---|
| 898 | handler=LogRecordStreamHandler):
|
|---|
| 899 | ThreadingTCPServer.__init__(self, (host, port), handler)
|
|---|
| 900 | self.abort = False
|
|---|
| 901 | self.timeout = 0.1
|
|---|
| 902 | self.finished = threading.Event()
|
|---|
| 903 |
|
|---|
| 904 | def serve_until_stopped(self):
|
|---|
| 905 | while not self.abort:
|
|---|
| 906 | rd, wr, ex = select.select([self.socket.fileno()], [], [],
|
|---|
| 907 | self.timeout)
|
|---|
| 908 | if rd:
|
|---|
| 909 | self.handle_request()
|
|---|
| 910 | # Notify the main thread that we're about to exit
|
|---|
| 911 | self.finished.set()
|
|---|
| 912 | # close the listen socket
|
|---|
| 913 | self.server_close()
|
|---|
| 914 |
|
|---|
| 915 |
|
|---|
| 916 | @unittest.skipUnless(threading, 'Threading required for this test.')
|
|---|
| 917 | class SocketHandlerTest(BaseTest):
|
|---|
| 918 |
|
|---|
| 919 | """Test for SocketHandler objects."""
|
|---|
| 920 |
|
|---|
| 921 | def setUp(self):
|
|---|
| 922 | """Set up a TCP server to receive log messages, and a SocketHandler
|
|---|
| 923 | pointing to that server's address and port."""
|
|---|
| 924 | BaseTest.setUp(self)
|
|---|
| 925 | self.tcpserver = LogRecordSocketReceiver(port=0)
|
|---|
| 926 | self.port = self.tcpserver.socket.getsockname()[1]
|
|---|
| 927 | self.threads = [
|
|---|
| 928 | threading.Thread(target=self.tcpserver.serve_until_stopped)]
|
|---|
| 929 | for thread in self.threads:
|
|---|
| 930 | thread.start()
|
|---|
| 931 |
|
|---|
| 932 | self.sock_hdlr = logging.handlers.SocketHandler('localhost', self.port)
|
|---|
| 933 | self.sock_hdlr.setFormatter(self.root_formatter)
|
|---|
| 934 | self.root_logger.removeHandler(self.root_logger.handlers[0])
|
|---|
| 935 | self.root_logger.addHandler(self.sock_hdlr)
|
|---|
| 936 |
|
|---|
| 937 | def tearDown(self):
|
|---|
| 938 | """Shutdown the TCP server."""
|
|---|
| 939 | try:
|
|---|
| 940 | self.tcpserver.abort = True
|
|---|
| 941 | del self.tcpserver
|
|---|
| 942 | self.root_logger.removeHandler(self.sock_hdlr)
|
|---|
| 943 | self.sock_hdlr.close()
|
|---|
| 944 | for thread in self.threads:
|
|---|
| 945 | thread.join(2.0)
|
|---|
| 946 | finally:
|
|---|
| 947 | BaseTest.tearDown(self)
|
|---|
| 948 |
|
|---|
| 949 | def get_output(self):
|
|---|
| 950 | """Get the log output as received by the TCP server."""
|
|---|
| 951 | # Signal the TCP receiver and wait for it to terminate.
|
|---|
| 952 | self.root_logger.critical(LogRecordStreamHandler.TCP_LOG_END)
|
|---|
| 953 | self.tcpserver.finished.wait(2.0)
|
|---|
| 954 | return self.tcpserver.log_output
|
|---|
| 955 |
|
|---|
| 956 | def test_output(self):
|
|---|
| 957 | # The log message sent to the SocketHandler is properly received.
|
|---|
| 958 | logger = logging.getLogger("tcp")
|
|---|
| 959 | logger.error("spam")
|
|---|
| 960 | logger.debug("eggs")
|
|---|
| 961 | self.assertEqual(self.get_output(), "spam\neggs\n")
|
|---|
| 962 |
|
|---|
| 963 |
|
|---|
| 964 | class MemoryTest(BaseTest):
|
|---|
| 965 |
|
|---|
| 966 | """Test memory persistence of logger objects."""
|
|---|
| 967 |
|
|---|
| 968 | def setUp(self):
|
|---|
| 969 | """Create a dict to remember potentially destroyed objects."""
|
|---|
| 970 | BaseTest.setUp(self)
|
|---|
| 971 | self._survivors = {}
|
|---|
| 972 |
|
|---|
| 973 | def _watch_for_survival(self, *args):
|
|---|
| 974 | """Watch the given objects for survival, by creating weakrefs to
|
|---|
| 975 | them."""
|
|---|
| 976 | for obj in args:
|
|---|
| 977 | key = id(obj), repr(obj)
|
|---|
| 978 | self._survivors[key] = weakref.ref(obj)
|
|---|
| 979 |
|
|---|
| 980 | def _assertTruesurvival(self):
|
|---|
| 981 | """Assert that all objects watched for survival have survived."""
|
|---|
| 982 | # Trigger cycle breaking.
|
|---|
| 983 | gc.collect()
|
|---|
| 984 | dead = []
|
|---|
| 985 | for (id_, repr_), ref in self._survivors.items():
|
|---|
| 986 | if ref() is None:
|
|---|
| 987 | dead.append(repr_)
|
|---|
| 988 | if dead:
|
|---|
| 989 | self.fail("%d objects should have survived "
|
|---|
| 990 | "but have been destroyed: %s" % (len(dead), ", ".join(dead)))
|
|---|
| 991 |
|
|---|
| 992 | def test_persistent_loggers(self):
|
|---|
| 993 | # Logger objects are persistent and retain their configuration, even
|
|---|
| 994 | # if visible references are destroyed.
|
|---|
| 995 | self.root_logger.setLevel(logging.INFO)
|
|---|
| 996 | foo = logging.getLogger("foo")
|
|---|
| 997 | self._watch_for_survival(foo)
|
|---|
| 998 | foo.setLevel(logging.DEBUG)
|
|---|
| 999 | self.root_logger.debug(self.next_message())
|
|---|
| 1000 | foo.debug(self.next_message())
|
|---|
| 1001 | self.assert_log_lines([
|
|---|
| 1002 | ('foo', 'DEBUG', '2'),
|
|---|
| 1003 | ])
|
|---|
| 1004 | del foo
|
|---|
| 1005 | # foo has survived.
|
|---|
| 1006 | self._assertTruesurvival()
|
|---|
| 1007 | # foo has retained its settings.
|
|---|
| 1008 | bar = logging.getLogger("foo")
|
|---|
| 1009 | bar.debug(self.next_message())
|
|---|
| 1010 | self.assert_log_lines([
|
|---|
| 1011 | ('foo', 'DEBUG', '2'),
|
|---|
| 1012 | ('foo', 'DEBUG', '3'),
|
|---|
| 1013 | ])
|
|---|
| 1014 |
|
|---|
| 1015 |
|
|---|
| 1016 | class EncodingTest(BaseTest):
|
|---|
| 1017 | def test_encoding_plain_file(self):
|
|---|
| 1018 | # In Python 2.x, a plain file object is treated as having no encoding.
|
|---|
| 1019 | log = logging.getLogger("test")
|
|---|
| 1020 | fn = tempfile.mktemp(".log")
|
|---|
| 1021 | # the non-ascii data we write to the log.
|
|---|
| 1022 | data = "foo\x80"
|
|---|
| 1023 | try:
|
|---|
| 1024 | handler = logging.FileHandler(fn)
|
|---|
| 1025 | log.addHandler(handler)
|
|---|
| 1026 | try:
|
|---|
| 1027 | # write non-ascii data to the log.
|
|---|
| 1028 | log.warning(data)
|
|---|
| 1029 | finally:
|
|---|
| 1030 | log.removeHandler(handler)
|
|---|
| 1031 | handler.close()
|
|---|
| 1032 | # check we wrote exactly those bytes, ignoring trailing \n etc
|
|---|
| 1033 | f = open(fn)
|
|---|
| 1034 | try:
|
|---|
| 1035 | self.assertEqual(f.read().rstrip(), data)
|
|---|
| 1036 | finally:
|
|---|
| 1037 | f.close()
|
|---|
| 1038 | finally:
|
|---|
| 1039 | if os.path.isfile(fn):
|
|---|
| 1040 | os.remove(fn)
|
|---|
| 1041 |
|
|---|
| 1042 | def test_encoding_cyrillic_unicode(self):
|
|---|
| 1043 | log = logging.getLogger("test")
|
|---|
| 1044 | #Get a message in Unicode: Do svidanya in Cyrillic (meaning goodbye)
|
|---|
| 1045 | message = u'\u0434\u043e \u0441\u0432\u0438\u0434\u0430\u043d\u0438\u044f'
|
|---|
| 1046 | #Ensure it's written in a Cyrillic encoding
|
|---|
| 1047 | writer_class = codecs.getwriter('cp1251')
|
|---|
| 1048 | writer_class.encoding = 'cp1251'
|
|---|
| 1049 | stream = cStringIO.StringIO()
|
|---|
| 1050 | writer = writer_class(stream, 'strict')
|
|---|
| 1051 | handler = logging.StreamHandler(writer)
|
|---|
| 1052 | log.addHandler(handler)
|
|---|
| 1053 | try:
|
|---|
| 1054 | log.warning(message)
|
|---|
| 1055 | finally:
|
|---|
| 1056 | log.removeHandler(handler)
|
|---|
| 1057 | handler.close()
|
|---|
| 1058 | # check we wrote exactly those bytes, ignoring trailing \n etc
|
|---|
| 1059 | s = stream.getvalue()
|
|---|
| 1060 | #Compare against what the data should be when encoded in CP-1251
|
|---|
| 1061 | self.assertEqual(s, '\xe4\xee \xf1\xe2\xe8\xe4\xe0\xed\xe8\xff\n')
|
|---|
| 1062 |
|
|---|
| 1063 | def test_encoding_utf16_unicode(self):
|
|---|
| 1064 | # Issue #19267
|
|---|
| 1065 | log = logging.getLogger("test")
|
|---|
| 1066 | message = u'b\u0142\u0105d'
|
|---|
| 1067 | writer_class = codecs.getwriter('utf-16-le')
|
|---|
| 1068 | writer_class.encoding = 'utf-16-le'
|
|---|
| 1069 | stream = cStringIO.StringIO()
|
|---|
| 1070 | writer = writer_class(stream, 'strict')
|
|---|
| 1071 | handler = logging.StreamHandler(writer)
|
|---|
| 1072 | log.addHandler(handler)
|
|---|
| 1073 | try:
|
|---|
| 1074 | log.warning(message)
|
|---|
| 1075 | finally:
|
|---|
| 1076 | log.removeHandler(handler)
|
|---|
| 1077 | handler.close()
|
|---|
| 1078 | s = stream.getvalue()
|
|---|
| 1079 | self.assertEqual(s, 'b\x00B\x01\x05\x01d\x00\n\x00')
|
|---|
| 1080 |
|
|---|
| 1081 |
|
|---|
| 1082 | class WarningsTest(BaseTest):
|
|---|
| 1083 |
|
|---|
| 1084 | def test_warnings(self):
|
|---|
| 1085 | with warnings.catch_warnings():
|
|---|
| 1086 | logging.captureWarnings(True)
|
|---|
| 1087 | try:
|
|---|
| 1088 | warnings.filterwarnings("always", category=UserWarning)
|
|---|
| 1089 | file = cStringIO.StringIO()
|
|---|
| 1090 | h = logging.StreamHandler(file)
|
|---|
| 1091 | logger = logging.getLogger("py.warnings")
|
|---|
| 1092 | logger.addHandler(h)
|
|---|
| 1093 | warnings.warn("I'm warning you...")
|
|---|
| 1094 | logger.removeHandler(h)
|
|---|
| 1095 | s = file.getvalue()
|
|---|
| 1096 | h.close()
|
|---|
| 1097 | self.assertTrue(s.find("UserWarning: I'm warning you...\n") > 0)
|
|---|
| 1098 |
|
|---|
| 1099 | #See if an explicit file uses the original implementation
|
|---|
| 1100 | file = cStringIO.StringIO()
|
|---|
| 1101 | warnings.showwarning("Explicit", UserWarning, "dummy.py", 42,
|
|---|
| 1102 | file, "Dummy line")
|
|---|
| 1103 | s = file.getvalue()
|
|---|
| 1104 | file.close()
|
|---|
| 1105 | self.assertEqual(s,
|
|---|
| 1106 | "dummy.py:42: UserWarning: Explicit\n Dummy line\n")
|
|---|
| 1107 | finally:
|
|---|
| 1108 | logging.captureWarnings(False)
|
|---|
| 1109 |
|
|---|
| 1110 |
|
|---|
| 1111 | def formatFunc(format, datefmt=None):
|
|---|
| 1112 | return logging.Formatter(format, datefmt)
|
|---|
| 1113 |
|
|---|
| 1114 | def handlerFunc():
|
|---|
| 1115 | return logging.StreamHandler()
|
|---|
| 1116 |
|
|---|
| 1117 | class CustomHandler(logging.StreamHandler):
|
|---|
| 1118 | pass
|
|---|
| 1119 |
|
|---|
| 1120 | class ConfigDictTest(BaseTest):
|
|---|
| 1121 |
|
|---|
| 1122 | """Reading logging config from a dictionary."""
|
|---|
| 1123 |
|
|---|
| 1124 | expected_log_pat = r"^([\w]+) \+\+ ([\w]+)$"
|
|---|
| 1125 |
|
|---|
| 1126 | # config0 is a standard configuration.
|
|---|
| 1127 | config0 = {
|
|---|
| 1128 | 'version': 1,
|
|---|
| 1129 | 'formatters': {
|
|---|
| 1130 | 'form1' : {
|
|---|
| 1131 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1132 | },
|
|---|
| 1133 | },
|
|---|
| 1134 | 'handlers' : {
|
|---|
| 1135 | 'hand1' : {
|
|---|
| 1136 | 'class' : 'logging.StreamHandler',
|
|---|
| 1137 | 'formatter' : 'form1',
|
|---|
| 1138 | 'level' : 'NOTSET',
|
|---|
| 1139 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1140 | },
|
|---|
| 1141 | },
|
|---|
| 1142 | 'root' : {
|
|---|
| 1143 | 'level' : 'WARNING',
|
|---|
| 1144 | 'handlers' : ['hand1'],
|
|---|
| 1145 | },
|
|---|
| 1146 | }
|
|---|
| 1147 |
|
|---|
| 1148 | # config1 adds a little to the standard configuration.
|
|---|
| 1149 | config1 = {
|
|---|
| 1150 | 'version': 1,
|
|---|
| 1151 | 'formatters': {
|
|---|
| 1152 | 'form1' : {
|
|---|
| 1153 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1154 | },
|
|---|
| 1155 | },
|
|---|
| 1156 | 'handlers' : {
|
|---|
| 1157 | 'hand1' : {
|
|---|
| 1158 | 'class' : 'logging.StreamHandler',
|
|---|
| 1159 | 'formatter' : 'form1',
|
|---|
| 1160 | 'level' : 'NOTSET',
|
|---|
| 1161 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1162 | },
|
|---|
| 1163 | },
|
|---|
| 1164 | 'loggers' : {
|
|---|
| 1165 | 'compiler.parser' : {
|
|---|
| 1166 | 'level' : 'DEBUG',
|
|---|
| 1167 | 'handlers' : ['hand1'],
|
|---|
| 1168 | },
|
|---|
| 1169 | },
|
|---|
| 1170 | 'root' : {
|
|---|
| 1171 | 'level' : 'WARNING',
|
|---|
| 1172 | },
|
|---|
| 1173 | }
|
|---|
| 1174 |
|
|---|
| 1175 | # config2 has a subtle configuration error that should be reported
|
|---|
| 1176 | config2 = {
|
|---|
| 1177 | 'version': 1,
|
|---|
| 1178 | 'formatters': {
|
|---|
| 1179 | 'form1' : {
|
|---|
| 1180 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1181 | },
|
|---|
| 1182 | },
|
|---|
| 1183 | 'handlers' : {
|
|---|
| 1184 | 'hand1' : {
|
|---|
| 1185 | 'class' : 'logging.StreamHandler',
|
|---|
| 1186 | 'formatter' : 'form1',
|
|---|
| 1187 | 'level' : 'NOTSET',
|
|---|
| 1188 | 'stream' : 'ext://sys.stdbout',
|
|---|
| 1189 | },
|
|---|
| 1190 | },
|
|---|
| 1191 | 'loggers' : {
|
|---|
| 1192 | 'compiler.parser' : {
|
|---|
| 1193 | 'level' : 'DEBUG',
|
|---|
| 1194 | 'handlers' : ['hand1'],
|
|---|
| 1195 | },
|
|---|
| 1196 | },
|
|---|
| 1197 | 'root' : {
|
|---|
| 1198 | 'level' : 'WARNING',
|
|---|
| 1199 | },
|
|---|
| 1200 | }
|
|---|
| 1201 |
|
|---|
| 1202 | #As config1 but with a misspelt level on a handler
|
|---|
| 1203 | config2a = {
|
|---|
| 1204 | 'version': 1,
|
|---|
| 1205 | 'formatters': {
|
|---|
| 1206 | 'form1' : {
|
|---|
| 1207 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1208 | },
|
|---|
| 1209 | },
|
|---|
| 1210 | 'handlers' : {
|
|---|
| 1211 | 'hand1' : {
|
|---|
| 1212 | 'class' : 'logging.StreamHandler',
|
|---|
| 1213 | 'formatter' : 'form1',
|
|---|
| 1214 | 'level' : 'NTOSET',
|
|---|
| 1215 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1216 | },
|
|---|
| 1217 | },
|
|---|
| 1218 | 'loggers' : {
|
|---|
| 1219 | 'compiler.parser' : {
|
|---|
| 1220 | 'level' : 'DEBUG',
|
|---|
| 1221 | 'handlers' : ['hand1'],
|
|---|
| 1222 | },
|
|---|
| 1223 | },
|
|---|
| 1224 | 'root' : {
|
|---|
| 1225 | 'level' : 'WARNING',
|
|---|
| 1226 | },
|
|---|
| 1227 | }
|
|---|
| 1228 |
|
|---|
| 1229 |
|
|---|
| 1230 | #As config1 but with a misspelt level on a logger
|
|---|
| 1231 | config2b = {
|
|---|
| 1232 | 'version': 1,
|
|---|
| 1233 | 'formatters': {
|
|---|
| 1234 | 'form1' : {
|
|---|
| 1235 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1236 | },
|
|---|
| 1237 | },
|
|---|
| 1238 | 'handlers' : {
|
|---|
| 1239 | 'hand1' : {
|
|---|
| 1240 | 'class' : 'logging.StreamHandler',
|
|---|
| 1241 | 'formatter' : 'form1',
|
|---|
| 1242 | 'level' : 'NOTSET',
|
|---|
| 1243 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1244 | },
|
|---|
| 1245 | },
|
|---|
| 1246 | 'loggers' : {
|
|---|
| 1247 | 'compiler.parser' : {
|
|---|
| 1248 | 'level' : 'DEBUG',
|
|---|
| 1249 | 'handlers' : ['hand1'],
|
|---|
| 1250 | },
|
|---|
| 1251 | },
|
|---|
| 1252 | 'root' : {
|
|---|
| 1253 | 'level' : 'WRANING',
|
|---|
| 1254 | },
|
|---|
| 1255 | }
|
|---|
| 1256 |
|
|---|
| 1257 | # config3 has a less subtle configuration error
|
|---|
| 1258 | config3 = {
|
|---|
| 1259 | 'version': 1,
|
|---|
| 1260 | 'formatters': {
|
|---|
| 1261 | 'form1' : {
|
|---|
| 1262 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1263 | },
|
|---|
| 1264 | },
|
|---|
| 1265 | 'handlers' : {
|
|---|
| 1266 | 'hand1' : {
|
|---|
| 1267 | 'class' : 'logging.StreamHandler',
|
|---|
| 1268 | 'formatter' : 'misspelled_name',
|
|---|
| 1269 | 'level' : 'NOTSET',
|
|---|
| 1270 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1271 | },
|
|---|
| 1272 | },
|
|---|
| 1273 | 'loggers' : {
|
|---|
| 1274 | 'compiler.parser' : {
|
|---|
| 1275 | 'level' : 'DEBUG',
|
|---|
| 1276 | 'handlers' : ['hand1'],
|
|---|
| 1277 | },
|
|---|
| 1278 | },
|
|---|
| 1279 | 'root' : {
|
|---|
| 1280 | 'level' : 'WARNING',
|
|---|
| 1281 | },
|
|---|
| 1282 | }
|
|---|
| 1283 |
|
|---|
| 1284 | # config4 specifies a custom formatter class to be loaded
|
|---|
| 1285 | config4 = {
|
|---|
| 1286 | 'version': 1,
|
|---|
| 1287 | 'formatters': {
|
|---|
| 1288 | 'form1' : {
|
|---|
| 1289 | '()' : __name__ + '.ExceptionFormatter',
|
|---|
| 1290 | 'format' : '%(levelname)s:%(name)s:%(message)s',
|
|---|
| 1291 | },
|
|---|
| 1292 | },
|
|---|
| 1293 | 'handlers' : {
|
|---|
| 1294 | 'hand1' : {
|
|---|
| 1295 | 'class' : 'logging.StreamHandler',
|
|---|
| 1296 | 'formatter' : 'form1',
|
|---|
| 1297 | 'level' : 'NOTSET',
|
|---|
| 1298 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1299 | },
|
|---|
| 1300 | },
|
|---|
| 1301 | 'root' : {
|
|---|
| 1302 | 'level' : 'NOTSET',
|
|---|
| 1303 | 'handlers' : ['hand1'],
|
|---|
| 1304 | },
|
|---|
| 1305 | }
|
|---|
| 1306 |
|
|---|
| 1307 | # As config4 but using an actual callable rather than a string
|
|---|
| 1308 | config4a = {
|
|---|
| 1309 | 'version': 1,
|
|---|
| 1310 | 'formatters': {
|
|---|
| 1311 | 'form1' : {
|
|---|
| 1312 | '()' : ExceptionFormatter,
|
|---|
| 1313 | 'format' : '%(levelname)s:%(name)s:%(message)s',
|
|---|
| 1314 | },
|
|---|
| 1315 | 'form2' : {
|
|---|
| 1316 | '()' : __name__ + '.formatFunc',
|
|---|
| 1317 | 'format' : '%(levelname)s:%(name)s:%(message)s',
|
|---|
| 1318 | },
|
|---|
| 1319 | 'form3' : {
|
|---|
| 1320 | '()' : formatFunc,
|
|---|
| 1321 | 'format' : '%(levelname)s:%(name)s:%(message)s',
|
|---|
| 1322 | },
|
|---|
| 1323 | },
|
|---|
| 1324 | 'handlers' : {
|
|---|
| 1325 | 'hand1' : {
|
|---|
| 1326 | 'class' : 'logging.StreamHandler',
|
|---|
| 1327 | 'formatter' : 'form1',
|
|---|
| 1328 | 'level' : 'NOTSET',
|
|---|
| 1329 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1330 | },
|
|---|
| 1331 | 'hand2' : {
|
|---|
| 1332 | '()' : handlerFunc,
|
|---|
| 1333 | },
|
|---|
| 1334 | },
|
|---|
| 1335 | 'root' : {
|
|---|
| 1336 | 'level' : 'NOTSET',
|
|---|
| 1337 | 'handlers' : ['hand1'],
|
|---|
| 1338 | },
|
|---|
| 1339 | }
|
|---|
| 1340 |
|
|---|
| 1341 | # config5 specifies a custom handler class to be loaded
|
|---|
| 1342 | config5 = {
|
|---|
| 1343 | 'version': 1,
|
|---|
| 1344 | 'formatters': {
|
|---|
| 1345 | 'form1' : {
|
|---|
| 1346 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1347 | },
|
|---|
| 1348 | },
|
|---|
| 1349 | 'handlers' : {
|
|---|
| 1350 | 'hand1' : {
|
|---|
| 1351 | 'class' : __name__ + '.CustomHandler',
|
|---|
| 1352 | 'formatter' : 'form1',
|
|---|
| 1353 | 'level' : 'NOTSET',
|
|---|
| 1354 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1355 | },
|
|---|
| 1356 | },
|
|---|
| 1357 | 'loggers' : {
|
|---|
| 1358 | 'compiler.parser' : {
|
|---|
| 1359 | 'level' : 'DEBUG',
|
|---|
| 1360 | 'handlers' : ['hand1'],
|
|---|
| 1361 | },
|
|---|
| 1362 | },
|
|---|
| 1363 | 'root' : {
|
|---|
| 1364 | 'level' : 'WARNING',
|
|---|
| 1365 | },
|
|---|
| 1366 | }
|
|---|
| 1367 |
|
|---|
| 1368 | # config6 specifies a custom handler class to be loaded
|
|---|
| 1369 | # but has bad arguments
|
|---|
| 1370 | config6 = {
|
|---|
| 1371 | 'version': 1,
|
|---|
| 1372 | 'formatters': {
|
|---|
| 1373 | 'form1' : {
|
|---|
| 1374 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1375 | },
|
|---|
| 1376 | },
|
|---|
| 1377 | 'handlers' : {
|
|---|
| 1378 | 'hand1' : {
|
|---|
| 1379 | 'class' : __name__ + '.CustomHandler',
|
|---|
| 1380 | 'formatter' : 'form1',
|
|---|
| 1381 | 'level' : 'NOTSET',
|
|---|
| 1382 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1383 | '9' : 'invalid parameter name',
|
|---|
| 1384 | },
|
|---|
| 1385 | },
|
|---|
| 1386 | 'loggers' : {
|
|---|
| 1387 | 'compiler.parser' : {
|
|---|
| 1388 | 'level' : 'DEBUG',
|
|---|
| 1389 | 'handlers' : ['hand1'],
|
|---|
| 1390 | },
|
|---|
| 1391 | },
|
|---|
| 1392 | 'root' : {
|
|---|
| 1393 | 'level' : 'WARNING',
|
|---|
| 1394 | },
|
|---|
| 1395 | }
|
|---|
| 1396 |
|
|---|
| 1397 | #config 7 does not define compiler.parser but defines compiler.lexer
|
|---|
| 1398 | #so compiler.parser should be disabled after applying it
|
|---|
| 1399 | config7 = {
|
|---|
| 1400 | 'version': 1,
|
|---|
| 1401 | 'formatters': {
|
|---|
| 1402 | 'form1' : {
|
|---|
| 1403 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1404 | },
|
|---|
| 1405 | },
|
|---|
| 1406 | 'handlers' : {
|
|---|
| 1407 | 'hand1' : {
|
|---|
| 1408 | 'class' : 'logging.StreamHandler',
|
|---|
| 1409 | 'formatter' : 'form1',
|
|---|
| 1410 | 'level' : 'NOTSET',
|
|---|
| 1411 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1412 | },
|
|---|
| 1413 | },
|
|---|
| 1414 | 'loggers' : {
|
|---|
| 1415 | 'compiler.lexer' : {
|
|---|
| 1416 | 'level' : 'DEBUG',
|
|---|
| 1417 | 'handlers' : ['hand1'],
|
|---|
| 1418 | },
|
|---|
| 1419 | },
|
|---|
| 1420 | 'root' : {
|
|---|
| 1421 | 'level' : 'WARNING',
|
|---|
| 1422 | },
|
|---|
| 1423 | }
|
|---|
| 1424 |
|
|---|
| 1425 | config8 = {
|
|---|
| 1426 | 'version': 1,
|
|---|
| 1427 | 'disable_existing_loggers' : False,
|
|---|
| 1428 | 'formatters': {
|
|---|
| 1429 | 'form1' : {
|
|---|
| 1430 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1431 | },
|
|---|
| 1432 | },
|
|---|
| 1433 | 'handlers' : {
|
|---|
| 1434 | 'hand1' : {
|
|---|
| 1435 | 'class' : 'logging.StreamHandler',
|
|---|
| 1436 | 'formatter' : 'form1',
|
|---|
| 1437 | 'level' : 'NOTSET',
|
|---|
| 1438 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1439 | },
|
|---|
| 1440 | },
|
|---|
| 1441 | 'loggers' : {
|
|---|
| 1442 | 'compiler' : {
|
|---|
| 1443 | 'level' : 'DEBUG',
|
|---|
| 1444 | 'handlers' : ['hand1'],
|
|---|
| 1445 | },
|
|---|
| 1446 | 'compiler.lexer' : {
|
|---|
| 1447 | },
|
|---|
| 1448 | },
|
|---|
| 1449 | 'root' : {
|
|---|
| 1450 | 'level' : 'WARNING',
|
|---|
| 1451 | },
|
|---|
| 1452 | }
|
|---|
| 1453 |
|
|---|
| 1454 | config9 = {
|
|---|
| 1455 | 'version': 1,
|
|---|
| 1456 | 'formatters': {
|
|---|
| 1457 | 'form1' : {
|
|---|
| 1458 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1459 | },
|
|---|
| 1460 | },
|
|---|
| 1461 | 'handlers' : {
|
|---|
| 1462 | 'hand1' : {
|
|---|
| 1463 | 'class' : 'logging.StreamHandler',
|
|---|
| 1464 | 'formatter' : 'form1',
|
|---|
| 1465 | 'level' : 'WARNING',
|
|---|
| 1466 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1467 | },
|
|---|
| 1468 | },
|
|---|
| 1469 | 'loggers' : {
|
|---|
| 1470 | 'compiler.parser' : {
|
|---|
| 1471 | 'level' : 'WARNING',
|
|---|
| 1472 | 'handlers' : ['hand1'],
|
|---|
| 1473 | },
|
|---|
| 1474 | },
|
|---|
| 1475 | 'root' : {
|
|---|
| 1476 | 'level' : 'NOTSET',
|
|---|
| 1477 | },
|
|---|
| 1478 | }
|
|---|
| 1479 |
|
|---|
| 1480 | config9a = {
|
|---|
| 1481 | 'version': 1,
|
|---|
| 1482 | 'incremental' : True,
|
|---|
| 1483 | 'handlers' : {
|
|---|
| 1484 | 'hand1' : {
|
|---|
| 1485 | 'level' : 'WARNING',
|
|---|
| 1486 | },
|
|---|
| 1487 | },
|
|---|
| 1488 | 'loggers' : {
|
|---|
| 1489 | 'compiler.parser' : {
|
|---|
| 1490 | 'level' : 'INFO',
|
|---|
| 1491 | },
|
|---|
| 1492 | },
|
|---|
| 1493 | }
|
|---|
| 1494 |
|
|---|
| 1495 | config9b = {
|
|---|
| 1496 | 'version': 1,
|
|---|
| 1497 | 'incremental' : True,
|
|---|
| 1498 | 'handlers' : {
|
|---|
| 1499 | 'hand1' : {
|
|---|
| 1500 | 'level' : 'INFO',
|
|---|
| 1501 | },
|
|---|
| 1502 | },
|
|---|
| 1503 | 'loggers' : {
|
|---|
| 1504 | 'compiler.parser' : {
|
|---|
| 1505 | 'level' : 'INFO',
|
|---|
| 1506 | },
|
|---|
| 1507 | },
|
|---|
| 1508 | }
|
|---|
| 1509 |
|
|---|
| 1510 | #As config1 but with a filter added
|
|---|
| 1511 | config10 = {
|
|---|
| 1512 | 'version': 1,
|
|---|
| 1513 | 'formatters': {
|
|---|
| 1514 | 'form1' : {
|
|---|
| 1515 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1516 | },
|
|---|
| 1517 | },
|
|---|
| 1518 | 'filters' : {
|
|---|
| 1519 | 'filt1' : {
|
|---|
| 1520 | 'name' : 'compiler.parser',
|
|---|
| 1521 | },
|
|---|
| 1522 | },
|
|---|
| 1523 | 'handlers' : {
|
|---|
| 1524 | 'hand1' : {
|
|---|
| 1525 | 'class' : 'logging.StreamHandler',
|
|---|
| 1526 | 'formatter' : 'form1',
|
|---|
| 1527 | 'level' : 'NOTSET',
|
|---|
| 1528 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1529 | 'filters' : ['filt1'],
|
|---|
| 1530 | },
|
|---|
| 1531 | },
|
|---|
| 1532 | 'loggers' : {
|
|---|
| 1533 | 'compiler.parser' : {
|
|---|
| 1534 | 'level' : 'DEBUG',
|
|---|
| 1535 | 'filters' : ['filt1'],
|
|---|
| 1536 | },
|
|---|
| 1537 | },
|
|---|
| 1538 | 'root' : {
|
|---|
| 1539 | 'level' : 'WARNING',
|
|---|
| 1540 | 'handlers' : ['hand1'],
|
|---|
| 1541 | },
|
|---|
| 1542 | }
|
|---|
| 1543 |
|
|---|
| 1544 | #As config1 but using cfg:// references
|
|---|
| 1545 | config11 = {
|
|---|
| 1546 | 'version': 1,
|
|---|
| 1547 | 'true_formatters': {
|
|---|
| 1548 | 'form1' : {
|
|---|
| 1549 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1550 | },
|
|---|
| 1551 | },
|
|---|
| 1552 | 'handler_configs': {
|
|---|
| 1553 | 'hand1' : {
|
|---|
| 1554 | 'class' : 'logging.StreamHandler',
|
|---|
| 1555 | 'formatter' : 'form1',
|
|---|
| 1556 | 'level' : 'NOTSET',
|
|---|
| 1557 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1558 | },
|
|---|
| 1559 | },
|
|---|
| 1560 | 'formatters' : 'cfg://true_formatters',
|
|---|
| 1561 | 'handlers' : {
|
|---|
| 1562 | 'hand1' : 'cfg://handler_configs[hand1]',
|
|---|
| 1563 | },
|
|---|
| 1564 | 'loggers' : {
|
|---|
| 1565 | 'compiler.parser' : {
|
|---|
| 1566 | 'level' : 'DEBUG',
|
|---|
| 1567 | 'handlers' : ['hand1'],
|
|---|
| 1568 | },
|
|---|
| 1569 | },
|
|---|
| 1570 | 'root' : {
|
|---|
| 1571 | 'level' : 'WARNING',
|
|---|
| 1572 | },
|
|---|
| 1573 | }
|
|---|
| 1574 |
|
|---|
| 1575 | #As config11 but missing the version key
|
|---|
| 1576 | config12 = {
|
|---|
| 1577 | 'true_formatters': {
|
|---|
| 1578 | 'form1' : {
|
|---|
| 1579 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1580 | },
|
|---|
| 1581 | },
|
|---|
| 1582 | 'handler_configs': {
|
|---|
| 1583 | 'hand1' : {
|
|---|
| 1584 | 'class' : 'logging.StreamHandler',
|
|---|
| 1585 | 'formatter' : 'form1',
|
|---|
| 1586 | 'level' : 'NOTSET',
|
|---|
| 1587 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1588 | },
|
|---|
| 1589 | },
|
|---|
| 1590 | 'formatters' : 'cfg://true_formatters',
|
|---|
| 1591 | 'handlers' : {
|
|---|
| 1592 | 'hand1' : 'cfg://handler_configs[hand1]',
|
|---|
| 1593 | },
|
|---|
| 1594 | 'loggers' : {
|
|---|
| 1595 | 'compiler.parser' : {
|
|---|
| 1596 | 'level' : 'DEBUG',
|
|---|
| 1597 | 'handlers' : ['hand1'],
|
|---|
| 1598 | },
|
|---|
| 1599 | },
|
|---|
| 1600 | 'root' : {
|
|---|
| 1601 | 'level' : 'WARNING',
|
|---|
| 1602 | },
|
|---|
| 1603 | }
|
|---|
| 1604 |
|
|---|
| 1605 | #As config11 but using an unsupported version
|
|---|
| 1606 | config13 = {
|
|---|
| 1607 | 'version': 2,
|
|---|
| 1608 | 'true_formatters': {
|
|---|
| 1609 | 'form1' : {
|
|---|
| 1610 | 'format' : '%(levelname)s ++ %(message)s',
|
|---|
| 1611 | },
|
|---|
| 1612 | },
|
|---|
| 1613 | 'handler_configs': {
|
|---|
| 1614 | 'hand1' : {
|
|---|
| 1615 | 'class' : 'logging.StreamHandler',
|
|---|
| 1616 | 'formatter' : 'form1',
|
|---|
| 1617 | 'level' : 'NOTSET',
|
|---|
| 1618 | 'stream' : 'ext://sys.stdout',
|
|---|
| 1619 | },
|
|---|
| 1620 | },
|
|---|
| 1621 | 'formatters' : 'cfg://true_formatters',
|
|---|
| 1622 | 'handlers' : {
|
|---|
| 1623 | 'hand1' : 'cfg://handler_configs[hand1]',
|
|---|
| 1624 | },
|
|---|
| 1625 | 'loggers' : {
|
|---|
| 1626 | 'compiler.parser' : {
|
|---|
| 1627 | 'level' : 'DEBUG',
|
|---|
| 1628 | 'handlers' : ['hand1'],
|
|---|
| 1629 | },
|
|---|
| 1630 | },
|
|---|
| 1631 | 'root' : {
|
|---|
| 1632 | 'level' : 'WARNING',
|
|---|
| 1633 | },
|
|---|
| 1634 | }
|
|---|
| 1635 |
|
|---|
| 1636 | out_of_order = {
|
|---|
| 1637 | "version": 1,
|
|---|
| 1638 | "formatters": {
|
|---|
| 1639 | "mySimpleFormatter": {
|
|---|
| 1640 | "format": "%(asctime)s (%(name)s) %(levelname)s: %(message)s"
|
|---|
| 1641 | }
|
|---|
| 1642 | },
|
|---|
| 1643 | "handlers": {
|
|---|
| 1644 | "fileGlobal": {
|
|---|
| 1645 | "class": "logging.StreamHandler",
|
|---|
| 1646 | "level": "DEBUG",
|
|---|
| 1647 | "formatter": "mySimpleFormatter"
|
|---|
| 1648 | },
|
|---|
| 1649 | "bufferGlobal": {
|
|---|
| 1650 | "class": "logging.handlers.MemoryHandler",
|
|---|
| 1651 | "capacity": 5,
|
|---|
| 1652 | "formatter": "mySimpleFormatter",
|
|---|
| 1653 | "target": "fileGlobal",
|
|---|
| 1654 | "level": "DEBUG"
|
|---|
| 1655 | }
|
|---|
| 1656 | },
|
|---|
| 1657 | "loggers": {
|
|---|
| 1658 | "mymodule": {
|
|---|
| 1659 | "level": "DEBUG",
|
|---|
| 1660 | "handlers": ["bufferGlobal"],
|
|---|
| 1661 | "propagate": "true"
|
|---|
| 1662 | }
|
|---|
| 1663 | }
|
|---|
| 1664 | }
|
|---|
| 1665 |
|
|---|
| 1666 | def apply_config(self, conf):
|
|---|
| 1667 | logging.config.dictConfig(conf)
|
|---|
| 1668 |
|
|---|
| 1669 | def test_config0_ok(self):
|
|---|
| 1670 | # A simple config which overrides the default settings.
|
|---|
| 1671 | with captured_stdout() as output:
|
|---|
| 1672 | self.apply_config(self.config0)
|
|---|
| 1673 | logger = logging.getLogger()
|
|---|
| 1674 | # Won't output anything
|
|---|
| 1675 | logger.info(self.next_message())
|
|---|
| 1676 | # Outputs a message
|
|---|
| 1677 | logger.error(self.next_message())
|
|---|
| 1678 | self.assert_log_lines([
|
|---|
| 1679 | ('ERROR', '2'),
|
|---|
| 1680 | ], stream=output)
|
|---|
| 1681 | # Original logger output is empty.
|
|---|
| 1682 | self.assert_log_lines([])
|
|---|
| 1683 |
|
|---|
| 1684 | def test_config1_ok(self, config=config1):
|
|---|
| 1685 | # A config defining a sub-parser as well.
|
|---|
| 1686 | with captured_stdout() as output:
|
|---|
| 1687 | self.apply_config(config)
|
|---|
| 1688 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1689 | # Both will output a message
|
|---|
| 1690 | logger.info(self.next_message())
|
|---|
| 1691 | logger.error(self.next_message())
|
|---|
| 1692 | self.assert_log_lines([
|
|---|
| 1693 | ('INFO', '1'),
|
|---|
| 1694 | ('ERROR', '2'),
|
|---|
| 1695 | ], stream=output)
|
|---|
| 1696 | # Original logger output is empty.
|
|---|
| 1697 | self.assert_log_lines([])
|
|---|
| 1698 |
|
|---|
| 1699 | def test_config2_failure(self):
|
|---|
| 1700 | # A simple config which overrides the default settings.
|
|---|
| 1701 | self.assertRaises(StandardError, self.apply_config, self.config2)
|
|---|
| 1702 |
|
|---|
| 1703 | def test_config2a_failure(self):
|
|---|
| 1704 | # A simple config which overrides the default settings.
|
|---|
| 1705 | self.assertRaises(StandardError, self.apply_config, self.config2a)
|
|---|
| 1706 |
|
|---|
| 1707 | def test_config2b_failure(self):
|
|---|
| 1708 | # A simple config which overrides the default settings.
|
|---|
| 1709 | self.assertRaises(StandardError, self.apply_config, self.config2b)
|
|---|
| 1710 |
|
|---|
| 1711 | def test_config3_failure(self):
|
|---|
| 1712 | # A simple config which overrides the default settings.
|
|---|
| 1713 | self.assertRaises(StandardError, self.apply_config, self.config3)
|
|---|
| 1714 |
|
|---|
| 1715 | def test_config4_ok(self):
|
|---|
| 1716 | # A config specifying a custom formatter class.
|
|---|
| 1717 | with captured_stdout() as output:
|
|---|
| 1718 | self.apply_config(self.config4)
|
|---|
| 1719 | #logger = logging.getLogger()
|
|---|
| 1720 | try:
|
|---|
| 1721 | raise RuntimeError()
|
|---|
| 1722 | except RuntimeError:
|
|---|
| 1723 | logging.exception("just testing")
|
|---|
| 1724 | sys.stdout.seek(0)
|
|---|
| 1725 | self.assertEqual(output.getvalue(),
|
|---|
| 1726 | "ERROR:root:just testing\nGot a [RuntimeError]\n")
|
|---|
| 1727 | # Original logger output is empty
|
|---|
| 1728 | self.assert_log_lines([])
|
|---|
| 1729 |
|
|---|
| 1730 | def test_config4a_ok(self):
|
|---|
| 1731 | # A config specifying a custom formatter class.
|
|---|
| 1732 | with captured_stdout() as output:
|
|---|
| 1733 | self.apply_config(self.config4a)
|
|---|
| 1734 | #logger = logging.getLogger()
|
|---|
| 1735 | try:
|
|---|
| 1736 | raise RuntimeError()
|
|---|
| 1737 | except RuntimeError:
|
|---|
| 1738 | logging.exception("just testing")
|
|---|
| 1739 | sys.stdout.seek(0)
|
|---|
| 1740 | self.assertEqual(output.getvalue(),
|
|---|
| 1741 | "ERROR:root:just testing\nGot a [RuntimeError]\n")
|
|---|
| 1742 | # Original logger output is empty
|
|---|
| 1743 | self.assert_log_lines([])
|
|---|
| 1744 |
|
|---|
| 1745 | def test_config5_ok(self):
|
|---|
| 1746 | self.test_config1_ok(config=self.config5)
|
|---|
| 1747 |
|
|---|
| 1748 | def test_config6_failure(self):
|
|---|
| 1749 | self.assertRaises(StandardError, self.apply_config, self.config6)
|
|---|
| 1750 |
|
|---|
| 1751 | def test_config7_ok(self):
|
|---|
| 1752 | with captured_stdout() as output:
|
|---|
| 1753 | self.apply_config(self.config1)
|
|---|
| 1754 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1755 | # Both will output a message
|
|---|
| 1756 | logger.info(self.next_message())
|
|---|
| 1757 | logger.error(self.next_message())
|
|---|
| 1758 | self.assert_log_lines([
|
|---|
| 1759 | ('INFO', '1'),
|
|---|
| 1760 | ('ERROR', '2'),
|
|---|
| 1761 | ], stream=output)
|
|---|
| 1762 | # Original logger output is empty.
|
|---|
| 1763 | self.assert_log_lines([])
|
|---|
| 1764 | with captured_stdout() as output:
|
|---|
| 1765 | self.apply_config(self.config7)
|
|---|
| 1766 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1767 | self.assertTrue(logger.disabled)
|
|---|
| 1768 | logger = logging.getLogger("compiler.lexer")
|
|---|
| 1769 | # Both will output a message
|
|---|
| 1770 | logger.info(self.next_message())
|
|---|
| 1771 | logger.error(self.next_message())
|
|---|
| 1772 | self.assert_log_lines([
|
|---|
| 1773 | ('INFO', '3'),
|
|---|
| 1774 | ('ERROR', '4'),
|
|---|
| 1775 | ], stream=output)
|
|---|
| 1776 | # Original logger output is empty.
|
|---|
| 1777 | self.assert_log_lines([])
|
|---|
| 1778 |
|
|---|
| 1779 | #Same as test_config_7_ok but don't disable old loggers.
|
|---|
| 1780 | def test_config_8_ok(self):
|
|---|
| 1781 | with captured_stdout() as output:
|
|---|
| 1782 | self.apply_config(self.config1)
|
|---|
| 1783 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1784 | # Both will output a message
|
|---|
| 1785 | logger.info(self.next_message())
|
|---|
| 1786 | logger.error(self.next_message())
|
|---|
| 1787 | self.assert_log_lines([
|
|---|
| 1788 | ('INFO', '1'),
|
|---|
| 1789 | ('ERROR', '2'),
|
|---|
| 1790 | ], stream=output)
|
|---|
| 1791 | # Original logger output is empty.
|
|---|
| 1792 | self.assert_log_lines([])
|
|---|
| 1793 | with captured_stdout() as output:
|
|---|
| 1794 | self.apply_config(self.config8)
|
|---|
| 1795 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1796 | self.assertFalse(logger.disabled)
|
|---|
| 1797 | # Both will output a message
|
|---|
| 1798 | logger.info(self.next_message())
|
|---|
| 1799 | logger.error(self.next_message())
|
|---|
| 1800 | logger = logging.getLogger("compiler.lexer")
|
|---|
| 1801 | # Both will output a message
|
|---|
| 1802 | logger.info(self.next_message())
|
|---|
| 1803 | logger.error(self.next_message())
|
|---|
| 1804 | self.assert_log_lines([
|
|---|
| 1805 | ('INFO', '3'),
|
|---|
| 1806 | ('ERROR', '4'),
|
|---|
| 1807 | ('INFO', '5'),
|
|---|
| 1808 | ('ERROR', '6'),
|
|---|
| 1809 | ], stream=output)
|
|---|
| 1810 | # Original logger output is empty.
|
|---|
| 1811 | self.assert_log_lines([])
|
|---|
| 1812 |
|
|---|
| 1813 | def test_config_9_ok(self):
|
|---|
| 1814 | with captured_stdout() as output:
|
|---|
| 1815 | self.apply_config(self.config9)
|
|---|
| 1816 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1817 | #Nothing will be output since both handler and logger are set to WARNING
|
|---|
| 1818 | logger.info(self.next_message())
|
|---|
| 1819 | self.assert_log_lines([], stream=output)
|
|---|
| 1820 | self.apply_config(self.config9a)
|
|---|
| 1821 | #Nothing will be output since both handler is still set to WARNING
|
|---|
| 1822 | logger.info(self.next_message())
|
|---|
| 1823 | self.assert_log_lines([], stream=output)
|
|---|
| 1824 | self.apply_config(self.config9b)
|
|---|
| 1825 | #Message should now be output
|
|---|
| 1826 | logger.info(self.next_message())
|
|---|
| 1827 | self.assert_log_lines([
|
|---|
| 1828 | ('INFO', '3'),
|
|---|
| 1829 | ], stream=output)
|
|---|
| 1830 |
|
|---|
| 1831 | def test_config_10_ok(self):
|
|---|
| 1832 | with captured_stdout() as output:
|
|---|
| 1833 | self.apply_config(self.config10)
|
|---|
| 1834 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1835 | logger.warning(self.next_message())
|
|---|
| 1836 | logger = logging.getLogger('compiler')
|
|---|
| 1837 | #Not output, because filtered
|
|---|
| 1838 | logger.warning(self.next_message())
|
|---|
| 1839 | logger = logging.getLogger('compiler.lexer')
|
|---|
| 1840 | #Not output, because filtered
|
|---|
| 1841 | logger.warning(self.next_message())
|
|---|
| 1842 | logger = logging.getLogger("compiler.parser.codegen")
|
|---|
| 1843 | #Output, as not filtered
|
|---|
| 1844 | logger.error(self.next_message())
|
|---|
| 1845 | self.assert_log_lines([
|
|---|
| 1846 | ('WARNING', '1'),
|
|---|
| 1847 | ('ERROR', '4'),
|
|---|
| 1848 | ], stream=output)
|
|---|
| 1849 |
|
|---|
| 1850 | def test_config11_ok(self):
|
|---|
| 1851 | self.test_config1_ok(self.config11)
|
|---|
| 1852 |
|
|---|
| 1853 | def test_config12_failure(self):
|
|---|
| 1854 | self.assertRaises(StandardError, self.apply_config, self.config12)
|
|---|
| 1855 |
|
|---|
| 1856 | def test_config13_failure(self):
|
|---|
| 1857 | self.assertRaises(StandardError, self.apply_config, self.config13)
|
|---|
| 1858 |
|
|---|
| 1859 | @unittest.skipUnless(threading, 'listen() needs threading to work')
|
|---|
| 1860 | def setup_via_listener(self, text):
|
|---|
| 1861 | # Ask for a randomly assigned port (by using port 0)
|
|---|
| 1862 | t = logging.config.listen(0)
|
|---|
| 1863 | t.start()
|
|---|
| 1864 | t.ready.wait()
|
|---|
| 1865 | # Now get the port allocated
|
|---|
| 1866 | port = t.port
|
|---|
| 1867 | t.ready.clear()
|
|---|
| 1868 | try:
|
|---|
| 1869 | sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
|
|---|
| 1870 | sock.settimeout(2.0)
|
|---|
| 1871 | sock.connect(('localhost', port))
|
|---|
| 1872 |
|
|---|
| 1873 | slen = struct.pack('>L', len(text))
|
|---|
| 1874 | s = slen + text
|
|---|
| 1875 | sentsofar = 0
|
|---|
| 1876 | left = len(s)
|
|---|
| 1877 | while left > 0:
|
|---|
| 1878 | sent = sock.send(s[sentsofar:])
|
|---|
| 1879 | sentsofar += sent
|
|---|
| 1880 | left -= sent
|
|---|
| 1881 | sock.close()
|
|---|
| 1882 | finally:
|
|---|
| 1883 | t.ready.wait(2.0)
|
|---|
| 1884 | logging.config.stopListening()
|
|---|
| 1885 | t.join(2.0)
|
|---|
| 1886 |
|
|---|
| 1887 | def test_listen_config_10_ok(self):
|
|---|
| 1888 | with captured_stdout() as output:
|
|---|
| 1889 | self.setup_via_listener(json.dumps(self.config10))
|
|---|
| 1890 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1891 | logger.warning(self.next_message())
|
|---|
| 1892 | logger = logging.getLogger('compiler')
|
|---|
| 1893 | #Not output, because filtered
|
|---|
| 1894 | logger.warning(self.next_message())
|
|---|
| 1895 | logger = logging.getLogger('compiler.lexer')
|
|---|
| 1896 | #Not output, because filtered
|
|---|
| 1897 | logger.warning(self.next_message())
|
|---|
| 1898 | logger = logging.getLogger("compiler.parser.codegen")
|
|---|
| 1899 | #Output, as not filtered
|
|---|
| 1900 | logger.error(self.next_message())
|
|---|
| 1901 | self.assert_log_lines([
|
|---|
| 1902 | ('WARNING', '1'),
|
|---|
| 1903 | ('ERROR', '4'),
|
|---|
| 1904 | ], stream=output)
|
|---|
| 1905 |
|
|---|
| 1906 | def test_listen_config_1_ok(self):
|
|---|
| 1907 | with captured_stdout() as output:
|
|---|
| 1908 | self.setup_via_listener(textwrap.dedent(ConfigFileTest.config1))
|
|---|
| 1909 | logger = logging.getLogger("compiler.parser")
|
|---|
| 1910 | # Both will output a message
|
|---|
| 1911 | logger.info(self.next_message())
|
|---|
| 1912 | logger.error(self.next_message())
|
|---|
| 1913 | self.assert_log_lines([
|
|---|
| 1914 | ('INFO', '1'),
|
|---|
| 1915 | ('ERROR', '2'),
|
|---|
| 1916 | ], stream=output)
|
|---|
| 1917 | # Original logger output is empty.
|
|---|
| 1918 | self.assert_log_lines([])
|
|---|
| 1919 |
|
|---|
| 1920 | def test_out_of_order(self):
|
|---|
| 1921 | self.apply_config(self.out_of_order)
|
|---|
| 1922 | handler = logging.getLogger('mymodule').handlers[0]
|
|---|
| 1923 | self.assertIsInstance(handler.target, logging.Handler)
|
|---|
| 1924 |
|
|---|
| 1925 | class ManagerTest(BaseTest):
|
|---|
| 1926 | def test_manager_loggerclass(self):
|
|---|
| 1927 | logged = []
|
|---|
| 1928 |
|
|---|
| 1929 | class MyLogger(logging.Logger):
|
|---|
| 1930 | def _log(self, level, msg, args, exc_info=None, extra=None):
|
|---|
| 1931 | logged.append(msg)
|
|---|
| 1932 |
|
|---|
| 1933 | man = logging.Manager(None)
|
|---|
| 1934 | self.assertRaises(TypeError, man.setLoggerClass, int)
|
|---|
| 1935 | man.setLoggerClass(MyLogger)
|
|---|
| 1936 | logger = man.getLogger('test')
|
|---|
| 1937 | logger.warning('should appear in logged')
|
|---|
| 1938 | logging.warning('should not appear in logged')
|
|---|
| 1939 |
|
|---|
| 1940 | self.assertEqual(logged, ['should appear in logged'])
|
|---|
| 1941 |
|
|---|
| 1942 |
|
|---|
| 1943 | class ChildLoggerTest(BaseTest):
|
|---|
| 1944 | def test_child_loggers(self):
|
|---|
| 1945 | r = logging.getLogger()
|
|---|
| 1946 | l1 = logging.getLogger('abc')
|
|---|
| 1947 | l2 = logging.getLogger('def.ghi')
|
|---|
| 1948 | c1 = r.getChild('xyz')
|
|---|
| 1949 | c2 = r.getChild('uvw.xyz')
|
|---|
| 1950 | self.assertTrue(c1 is logging.getLogger('xyz'))
|
|---|
| 1951 | self.assertTrue(c2 is logging.getLogger('uvw.xyz'))
|
|---|
| 1952 | c1 = l1.getChild('def')
|
|---|
| 1953 | c2 = c1.getChild('ghi')
|
|---|
| 1954 | c3 = l1.getChild('def.ghi')
|
|---|
| 1955 | self.assertTrue(c1 is logging.getLogger('abc.def'))
|
|---|
| 1956 | self.assertTrue(c2 is logging.getLogger('abc.def.ghi'))
|
|---|
| 1957 | self.assertTrue(c2 is c3)
|
|---|
| 1958 |
|
|---|
| 1959 |
|
|---|
| 1960 | class HandlerTest(BaseTest):
|
|---|
| 1961 |
|
|---|
| 1962 | @unittest.skipIf(os.name == 'nt', 'WatchedFileHandler not appropriate for Windows.')
|
|---|
| 1963 | @unittest.skipUnless(threading, 'Threading required for this test.')
|
|---|
| 1964 | def test_race(self):
|
|---|
| 1965 | # Issue #14632 refers.
|
|---|
| 1966 | def remove_loop(fname, tries):
|
|---|
| 1967 | for _ in range(tries):
|
|---|
| 1968 | try:
|
|---|
| 1969 | os.unlink(fname)
|
|---|
| 1970 | except OSError:
|
|---|
| 1971 | pass
|
|---|
| 1972 | time.sleep(0.004 * random.randint(0, 4))
|
|---|
| 1973 |
|
|---|
| 1974 | del_count = 500
|
|---|
| 1975 | log_count = 500
|
|---|
| 1976 |
|
|---|
| 1977 | for delay in (False, True):
|
|---|
| 1978 | fd, fn = tempfile.mkstemp('.log', 'test_logging-3-')
|
|---|
| 1979 | os.close(fd)
|
|---|
| 1980 | remover = threading.Thread(target=remove_loop, args=(fn, del_count))
|
|---|
| 1981 | remover.daemon = True
|
|---|
| 1982 | remover.start()
|
|---|
| 1983 | h = logging.handlers.WatchedFileHandler(fn, delay=delay)
|
|---|
| 1984 | f = logging.Formatter('%(asctime)s: %(levelname)s: %(message)s')
|
|---|
| 1985 | h.setFormatter(f)
|
|---|
| 1986 | try:
|
|---|
| 1987 | for _ in range(log_count):
|
|---|
| 1988 | time.sleep(0.005)
|
|---|
| 1989 | r = logging.makeLogRecord({'msg': 'testing' })
|
|---|
| 1990 | h.handle(r)
|
|---|
| 1991 | finally:
|
|---|
| 1992 | remover.join()
|
|---|
| 1993 | try:
|
|---|
| 1994 | h.close()
|
|---|
| 1995 | except ValueError:
|
|---|
| 1996 | pass
|
|---|
| 1997 | if os.path.exists(fn):
|
|---|
| 1998 | os.unlink(fn)
|
|---|
| 1999 |
|
|---|
| 2000 |
|
|---|
| 2001 | # Set the locale to the platform-dependent default. I have no idea
|
|---|
| 2002 | # why the test does this, but in any case we save the current locale
|
|---|
| 2003 | # first and restore it at the end.
|
|---|
| 2004 | @run_with_locale('LC_ALL', '')
|
|---|
| 2005 | def test_main():
|
|---|
| 2006 | run_unittest(BuiltinLevelsTest, BasicFilterTest,
|
|---|
| 2007 | CustomLevelsAndFiltersTest, MemoryHandlerTest,
|
|---|
| 2008 | ConfigFileTest, SocketHandlerTest, MemoryTest,
|
|---|
| 2009 | EncodingTest, WarningsTest, ConfigDictTest, ManagerTest,
|
|---|
| 2010 | ChildLoggerTest, HandlerTest)
|
|---|
| 2011 |
|
|---|
| 2012 | if __name__ == "__main__":
|
|---|
| 2013 | test_main()
|
|---|
