move sections
[python/dscho.git] / Lib / test / test_logging.py
blobed17d15f2ee1ddde3a7521dd5ed9591959bd1883
1 #!/usr/bin/env python
3 # Copyright 2001-2010 by Vinay Sajip. All Rights Reserved.
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.
19 """Test harness for the logging module. Run all tests.
21 Copyright (C) 2001-2010 Vinay Sajip. All Rights Reserved.
22 """
24 import logging
25 import logging.handlers
26 import logging.config
28 import codecs
29 import cPickle
30 import cStringIO
31 import gc
32 import json
33 import os
34 import re
35 import select
36 import socket
37 from SocketServer import ThreadingTCPServer, StreamRequestHandler
38 import struct
39 import sys
40 import tempfile
41 from test.test_support import captured_stdout, run_with_locale, run_unittest
42 import textwrap
43 import unittest
44 import warnings
45 import weakref
46 try:
47 import threading
48 except ImportError:
49 threading = None
51 class BaseTest(unittest.TestCase):
53 """Base class for logging tests."""
55 log_format = "%(name)s -> %(levelname)s: %(message)s"
56 expected_log_pat = r"^([\w.]+) -> ([\w]+): ([\d]+)$"
57 message_num = 0
59 def setUp(self):
60 """Setup the default logging stream to an internal StringIO instance,
61 so that we can examine log output as we want."""
62 logger_dict = logging.getLogger().manager.loggerDict
63 logging._acquireLock()
64 try:
65 self.saved_handlers = logging._handlers.copy()
66 self.saved_handler_list = logging._handlerList[:]
67 self.saved_loggers = logger_dict.copy()
68 self.saved_level_names = logging._levelNames.copy()
69 finally:
70 logging._releaseLock()
72 # Set two unused loggers: one non-ASCII and one Unicode.
73 # This is to test correct operation when sorting existing
74 # loggers in the configuration code. See issue 8201.
75 logging.getLogger("\xab\xd7\xbb")
76 logging.getLogger(u"\u013f\u00d6\u0047")
78 self.root_logger = logging.getLogger("")
79 self.original_logging_level = self.root_logger.getEffectiveLevel()
81 self.stream = cStringIO.StringIO()
82 self.root_logger.setLevel(logging.DEBUG)
83 self.root_hdlr = logging.StreamHandler(self.stream)
84 self.root_formatter = logging.Formatter(self.log_format)
85 self.root_hdlr.setFormatter(self.root_formatter)
86 self.root_logger.addHandler(self.root_hdlr)
88 def tearDown(self):
89 """Remove our logging stream, and restore the original logging
90 level."""
91 self.stream.close()
92 self.root_logger.removeHandler(self.root_hdlr)
93 while self.root_logger.handlers:
94 h = self.root_logger.handlers[0]
95 self.root_logger.removeHandler(h)
96 h.close()
97 self.root_logger.setLevel(self.original_logging_level)
98 logging._acquireLock()
99 try:
100 logging._levelNames.clear()
101 logging._levelNames.update(self.saved_level_names)
102 logging._handlers.clear()
103 logging._handlers.update(self.saved_handlers)
104 logging._handlerList[:] = self.saved_handler_list
105 loggerDict = logging.getLogger().manager.loggerDict
106 loggerDict.clear()
107 loggerDict.update(self.saved_loggers)
108 finally:
109 logging._releaseLock()
111 def assert_log_lines(self, expected_values, stream=None):
112 """Match the collected log lines against the regular expression
113 self.expected_log_pat, and compare the extracted group values to
114 the expected_values list of tuples."""
115 stream = stream or self.stream
116 pat = re.compile(self.expected_log_pat)
117 try:
118 stream.reset()
119 actual_lines = stream.readlines()
120 except AttributeError:
121 # StringIO.StringIO lacks a reset() method.
122 actual_lines = stream.getvalue().splitlines()
123 self.assertEquals(len(actual_lines), len(expected_values))
124 for actual, expected in zip(actual_lines, expected_values):
125 match = pat.search(actual)
126 if not match:
127 self.fail("Log line does not match expected pattern:\n" +
128 actual)
129 self.assertEquals(tuple(match.groups()), expected)
130 s = stream.read()
131 if s:
132 self.fail("Remaining output at end of log stream:\n" + s)
134 def next_message(self):
135 """Generate a message consisting solely of an auto-incrementing
136 integer."""
137 self.message_num += 1
138 return "%d" % self.message_num
141 class BuiltinLevelsTest(BaseTest):
142 """Test builtin levels and their inheritance."""
144 def test_flat(self):
145 #Logging levels in a flat logger namespace.
146 m = self.next_message
148 ERR = logging.getLogger("ERR")
149 ERR.setLevel(logging.ERROR)
150 INF = logging.getLogger("INF")
151 INF.setLevel(logging.INFO)
152 DEB = logging.getLogger("DEB")
153 DEB.setLevel(logging.DEBUG)
155 # These should log.
156 ERR.log(logging.CRITICAL, m())
157 ERR.error(m())
159 INF.log(logging.CRITICAL, m())
160 INF.error(m())
161 INF.warn(m())
162 INF.info(m())
164 DEB.log(logging.CRITICAL, m())
165 DEB.error(m())
166 DEB.warn (m())
167 DEB.info (m())
168 DEB.debug(m())
170 # These should not log.
171 ERR.warn(m())
172 ERR.info(m())
173 ERR.debug(m())
175 INF.debug(m())
177 self.assert_log_lines([
178 ('ERR', 'CRITICAL', '1'),
179 ('ERR', 'ERROR', '2'),
180 ('INF', 'CRITICAL', '3'),
181 ('INF', 'ERROR', '4'),
182 ('INF', 'WARNING', '5'),
183 ('INF', 'INFO', '6'),
184 ('DEB', 'CRITICAL', '7'),
185 ('DEB', 'ERROR', '8'),
186 ('DEB', 'WARNING', '9'),
187 ('DEB', 'INFO', '10'),
188 ('DEB', 'DEBUG', '11'),
191 def test_nested_explicit(self):
192 # Logging levels in a nested namespace, all explicitly set.
193 m = self.next_message
195 INF = logging.getLogger("INF")
196 INF.setLevel(logging.INFO)
197 INF_ERR = logging.getLogger("INF.ERR")
198 INF_ERR.setLevel(logging.ERROR)
200 # These should log.
201 INF_ERR.log(logging.CRITICAL, m())
202 INF_ERR.error(m())
204 # These should not log.
205 INF_ERR.warn(m())
206 INF_ERR.info(m())
207 INF_ERR.debug(m())
209 self.assert_log_lines([
210 ('INF.ERR', 'CRITICAL', '1'),
211 ('INF.ERR', 'ERROR', '2'),
214 def test_nested_inherited(self):
215 #Logging levels in a nested namespace, inherited from parent loggers.
216 m = self.next_message
218 INF = logging.getLogger("INF")
219 INF.setLevel(logging.INFO)
220 INF_ERR = logging.getLogger("INF.ERR")
221 INF_ERR.setLevel(logging.ERROR)
222 INF_UNDEF = logging.getLogger("INF.UNDEF")
223 INF_ERR_UNDEF = logging.getLogger("INF.ERR.UNDEF")
224 UNDEF = logging.getLogger("UNDEF")
226 # These should log.
227 INF_UNDEF.log(logging.CRITICAL, m())
228 INF_UNDEF.error(m())
229 INF_UNDEF.warn(m())
230 INF_UNDEF.info(m())
231 INF_ERR_UNDEF.log(logging.CRITICAL, m())
232 INF_ERR_UNDEF.error(m())
234 # These should not log.
235 INF_UNDEF.debug(m())
236 INF_ERR_UNDEF.warn(m())
237 INF_ERR_UNDEF.info(m())
238 INF_ERR_UNDEF.debug(m())
240 self.assert_log_lines([
241 ('INF.UNDEF', 'CRITICAL', '1'),
242 ('INF.UNDEF', 'ERROR', '2'),
243 ('INF.UNDEF', 'WARNING', '3'),
244 ('INF.UNDEF', 'INFO', '4'),
245 ('INF.ERR.UNDEF', 'CRITICAL', '5'),
246 ('INF.ERR.UNDEF', 'ERROR', '6'),
249 def test_nested_with_virtual_parent(self):
250 # Logging levels when some parent does not exist yet.
251 m = self.next_message
253 INF = logging.getLogger("INF")
254 GRANDCHILD = logging.getLogger("INF.BADPARENT.UNDEF")
255 CHILD = logging.getLogger("INF.BADPARENT")
256 INF.setLevel(logging.INFO)
258 # These should log.
259 GRANDCHILD.log(logging.FATAL, m())
260 GRANDCHILD.info(m())
261 CHILD.log(logging.FATAL, m())
262 CHILD.info(m())
264 # These should not log.
265 GRANDCHILD.debug(m())
266 CHILD.debug(m())
268 self.assert_log_lines([
269 ('INF.BADPARENT.UNDEF', 'CRITICAL', '1'),
270 ('INF.BADPARENT.UNDEF', 'INFO', '2'),
271 ('INF.BADPARENT', 'CRITICAL', '3'),
272 ('INF.BADPARENT', 'INFO', '4'),
276 class BasicFilterTest(BaseTest):
278 """Test the bundled Filter class."""
280 def test_filter(self):
281 # Only messages satisfying the specified criteria pass through the
282 # filter.
283 filter_ = logging.Filter("spam.eggs")
284 handler = self.root_logger.handlers[0]
285 try:
286 handler.addFilter(filter_)
287 spam = logging.getLogger("spam")
288 spam_eggs = logging.getLogger("spam.eggs")
289 spam_eggs_fish = logging.getLogger("spam.eggs.fish")
290 spam_bakedbeans = logging.getLogger("spam.bakedbeans")
292 spam.info(self.next_message())
293 spam_eggs.info(self.next_message()) # Good.
294 spam_eggs_fish.info(self.next_message()) # Good.
295 spam_bakedbeans.info(self.next_message())
297 self.assert_log_lines([
298 ('spam.eggs', 'INFO', '2'),
299 ('spam.eggs.fish', 'INFO', '3'),
301 finally:
302 handler.removeFilter(filter_)
306 # First, we define our levels. There can be as many as you want - the only
307 # limitations are that they should be integers, the lowest should be > 0 and
308 # larger values mean less information being logged. If you need specific
309 # level values which do not fit into these limitations, you can use a
310 # mapping dictionary to convert between your application levels and the
311 # logging system.
313 SILENT = 120
314 TACITURN = 119
315 TERSE = 118
316 EFFUSIVE = 117
317 SOCIABLE = 116
318 VERBOSE = 115
319 TALKATIVE = 114
320 GARRULOUS = 113
321 CHATTERBOX = 112
322 BORING = 111
324 LEVEL_RANGE = range(BORING, SILENT + 1)
327 # Next, we define names for our levels. You don't need to do this - in which
328 # case the system will use "Level n" to denote the text for the level.
330 my_logging_levels = {
331 SILENT : 'Silent',
332 TACITURN : 'Taciturn',
333 TERSE : 'Terse',
334 EFFUSIVE : 'Effusive',
335 SOCIABLE : 'Sociable',
336 VERBOSE : 'Verbose',
337 TALKATIVE : 'Talkative',
338 GARRULOUS : 'Garrulous',
339 CHATTERBOX : 'Chatterbox',
340 BORING : 'Boring',
343 class GarrulousFilter(logging.Filter):
345 """A filter which blocks garrulous messages."""
347 def filter(self, record):
348 return record.levelno != GARRULOUS
350 class VerySpecificFilter(logging.Filter):
352 """A filter which blocks sociable and taciturn messages."""
354 def filter(self, record):
355 return record.levelno not in [SOCIABLE, TACITURN]
358 class CustomLevelsAndFiltersTest(BaseTest):
360 """Test various filtering possibilities with custom logging levels."""
362 # Skip the logger name group.
363 expected_log_pat = r"^[\w.]+ -> ([\w]+): ([\d]+)$"
365 def setUp(self):
366 BaseTest.setUp(self)
367 for k, v in my_logging_levels.items():
368 logging.addLevelName(k, v)
370 def log_at_all_levels(self, logger):
371 for lvl in LEVEL_RANGE:
372 logger.log(lvl, self.next_message())
374 def test_logger_filter(self):
375 # Filter at logger level.
376 self.root_logger.setLevel(VERBOSE)
377 # Levels >= 'Verbose' are good.
378 self.log_at_all_levels(self.root_logger)
379 self.assert_log_lines([
380 ('Verbose', '5'),
381 ('Sociable', '6'),
382 ('Effusive', '7'),
383 ('Terse', '8'),
384 ('Taciturn', '9'),
385 ('Silent', '10'),
388 def test_handler_filter(self):
389 # Filter at handler level.
390 self.root_logger.handlers[0].setLevel(SOCIABLE)
391 try:
392 # Levels >= 'Sociable' are good.
393 self.log_at_all_levels(self.root_logger)
394 self.assert_log_lines([
395 ('Sociable', '6'),
396 ('Effusive', '7'),
397 ('Terse', '8'),
398 ('Taciturn', '9'),
399 ('Silent', '10'),
401 finally:
402 self.root_logger.handlers[0].setLevel(logging.NOTSET)
404 def test_specific_filters(self):
405 # Set a specific filter object on the handler, and then add another
406 # filter object on the logger itself.
407 handler = self.root_logger.handlers[0]
408 specific_filter = None
409 garr = GarrulousFilter()
410 handler.addFilter(garr)
411 try:
412 self.log_at_all_levels(self.root_logger)
413 first_lines = [
414 # Notice how 'Garrulous' is missing
415 ('Boring', '1'),
416 ('Chatterbox', '2'),
417 ('Talkative', '4'),
418 ('Verbose', '5'),
419 ('Sociable', '6'),
420 ('Effusive', '7'),
421 ('Terse', '8'),
422 ('Taciturn', '9'),
423 ('Silent', '10'),
425 self.assert_log_lines(first_lines)
427 specific_filter = VerySpecificFilter()
428 self.root_logger.addFilter(specific_filter)
429 self.log_at_all_levels(self.root_logger)
430 self.assert_log_lines(first_lines + [
431 # Not only 'Garrulous' is still missing, but also 'Sociable'
432 # and 'Taciturn'
433 ('Boring', '11'),
434 ('Chatterbox', '12'),
435 ('Talkative', '14'),
436 ('Verbose', '15'),
437 ('Effusive', '17'),
438 ('Terse', '18'),
439 ('Silent', '20'),
441 finally:
442 if specific_filter:
443 self.root_logger.removeFilter(specific_filter)
444 handler.removeFilter(garr)
447 class MemoryHandlerTest(BaseTest):
449 """Tests for the MemoryHandler."""
451 # Do not bother with a logger name group.
452 expected_log_pat = r"^[\w.]+ -> ([\w]+): ([\d]+)$"
454 def setUp(self):
455 BaseTest.setUp(self)
456 self.mem_hdlr = logging.handlers.MemoryHandler(10, logging.WARNING,
457 self.root_hdlr)
458 self.mem_logger = logging.getLogger('mem')
459 self.mem_logger.propagate = 0
460 self.mem_logger.addHandler(self.mem_hdlr)
462 def tearDown(self):
463 self.mem_hdlr.close()
464 BaseTest.tearDown(self)
466 def test_flush(self):
467 # The memory handler flushes to its target handler based on specific
468 # criteria (message count and message level).
469 self.mem_logger.debug(self.next_message())
470 self.assert_log_lines([])
471 self.mem_logger.info(self.next_message())
472 self.assert_log_lines([])
473 # This will flush because the level is >= logging.WARNING
474 self.mem_logger.warn(self.next_message())
475 lines = [
476 ('DEBUG', '1'),
477 ('INFO', '2'),
478 ('WARNING', '3'),
480 self.assert_log_lines(lines)
481 for n in (4, 14):
482 for i in range(9):
483 self.mem_logger.debug(self.next_message())
484 self.assert_log_lines(lines)
485 # This will flush because it's the 10th message since the last
486 # flush.
487 self.mem_logger.debug(self.next_message())
488 lines = lines + [('DEBUG', str(i)) for i in range(n, n + 10)]
489 self.assert_log_lines(lines)
491 self.mem_logger.debug(self.next_message())
492 self.assert_log_lines(lines)
495 class ExceptionFormatter(logging.Formatter):
496 """A special exception formatter."""
497 def formatException(self, ei):
498 return "Got a [%s]" % ei[0].__name__
501 class ConfigFileTest(BaseTest):
503 """Reading logging config from a .ini-style config file."""
505 expected_log_pat = r"^([\w]+) \+\+ ([\w]+)$"
507 # config0 is a standard configuration.
508 config0 = """
509 [loggers]
510 keys=root
512 [handlers]
513 keys=hand1
515 [formatters]
516 keys=form1
518 [logger_root]
519 level=WARNING
520 handlers=hand1
522 [handler_hand1]
523 class=StreamHandler
524 level=NOTSET
525 formatter=form1
526 args=(sys.stdout,)
528 [formatter_form1]
529 format=%(levelname)s ++ %(message)s
530 datefmt=
533 # config1 adds a little to the standard configuration.
534 config1 = """
535 [loggers]
536 keys=root,parser
538 [handlers]
539 keys=hand1
541 [formatters]
542 keys=form1
544 [logger_root]
545 level=WARNING
546 handlers=
548 [logger_parser]
549 level=DEBUG
550 handlers=hand1
551 propagate=1
552 qualname=compiler.parser
554 [handler_hand1]
555 class=StreamHandler
556 level=NOTSET
557 formatter=form1
558 args=(sys.stdout,)
560 [formatter_form1]
561 format=%(levelname)s ++ %(message)s
562 datefmt=
565 # config2 has a subtle configuration error that should be reported
566 config2 = config1.replace("sys.stdout", "sys.stbout")
568 # config3 has a less subtle configuration error
569 config3 = config1.replace("formatter=form1", "formatter=misspelled_name")
571 # config4 specifies a custom formatter class to be loaded
572 config4 = """
573 [loggers]
574 keys=root
576 [handlers]
577 keys=hand1
579 [formatters]
580 keys=form1
582 [logger_root]
583 level=NOTSET
584 handlers=hand1
586 [handler_hand1]
587 class=StreamHandler
588 level=NOTSET
589 formatter=form1
590 args=(sys.stdout,)
592 [formatter_form1]
593 class=""" + __name__ + """.ExceptionFormatter
594 format=%(levelname)s:%(name)s:%(message)s
595 datefmt=
598 # config5 specifies a custom handler class to be loaded
599 config5 = config1.replace('class=StreamHandler', 'class=logging.StreamHandler')
601 # config6 uses ', ' delimiters in the handlers and formatters sections
602 config6 = """
603 [loggers]
604 keys=root,parser
606 [handlers]
607 keys=hand1, hand2
609 [formatters]
610 keys=form1, form2
612 [logger_root]
613 level=WARNING
614 handlers=
616 [logger_parser]
617 level=DEBUG
618 handlers=hand1
619 propagate=1
620 qualname=compiler.parser
622 [handler_hand1]
623 class=StreamHandler
624 level=NOTSET
625 formatter=form1
626 args=(sys.stdout,)
628 [handler_hand2]
629 class=StreamHandler
630 level=NOTSET
631 formatter=form1
632 args=(sys.stderr,)
634 [formatter_form1]
635 format=%(levelname)s ++ %(message)s
636 datefmt=
638 [formatter_form2]
639 format=%(message)s
640 datefmt=
643 def apply_config(self, conf):
644 file = cStringIO.StringIO(textwrap.dedent(conf))
645 logging.config.fileConfig(file)
647 def test_config0_ok(self):
648 # A simple config file which overrides the default settings.
649 with captured_stdout() as output:
650 self.apply_config(self.config0)
651 logger = logging.getLogger()
652 # Won't output anything
653 logger.info(self.next_message())
654 # Outputs a message
655 logger.error(self.next_message())
656 self.assert_log_lines([
657 ('ERROR', '2'),
658 ], stream=output)
659 # Original logger output is empty.
660 self.assert_log_lines([])
662 def test_config1_ok(self, config=config1):
663 # A config file defining a sub-parser as well.
664 with captured_stdout() as output:
665 self.apply_config(config)
666 logger = logging.getLogger("compiler.parser")
667 # Both will output a message
668 logger.info(self.next_message())
669 logger.error(self.next_message())
670 self.assert_log_lines([
671 ('INFO', '1'),
672 ('ERROR', '2'),
673 ], stream=output)
674 # Original logger output is empty.
675 self.assert_log_lines([])
677 def test_config2_failure(self):
678 # A simple config file which overrides the default settings.
679 self.assertRaises(StandardError, self.apply_config, self.config2)
681 def test_config3_failure(self):
682 # A simple config file which overrides the default settings.
683 self.assertRaises(StandardError, self.apply_config, self.config3)
685 def test_config4_ok(self):
686 # A config file specifying a custom formatter class.
687 with captured_stdout() as output:
688 self.apply_config(self.config4)
689 logger = logging.getLogger()
690 try:
691 raise RuntimeError()
692 except RuntimeError:
693 logging.exception("just testing")
694 sys.stdout.seek(0)
695 self.assertEquals(output.getvalue(),
696 "ERROR:root:just testing\nGot a [RuntimeError]\n")
697 # Original logger output is empty
698 self.assert_log_lines([])
700 def test_config5_ok(self):
701 self.test_config1_ok(config=self.config5)
703 def test_config6_ok(self):
704 self.test_config1_ok(config=self.config6)
706 class LogRecordStreamHandler(StreamRequestHandler):
708 """Handler for a streaming logging request. It saves the log message in the
709 TCP server's 'log_output' attribute."""
711 TCP_LOG_END = "!!!END!!!"
713 def handle(self):
714 """Handle multiple requests - each expected to be of 4-byte length,
715 followed by the LogRecord in pickle format. Logs the record
716 according to whatever policy is configured locally."""
717 while True:
718 chunk = self.connection.recv(4)
719 if len(chunk) < 4:
720 break
721 slen = struct.unpack(">L", chunk)[0]
722 chunk = self.connection.recv(slen)
723 while len(chunk) < slen:
724 chunk = chunk + self.connection.recv(slen - len(chunk))
725 obj = self.unpickle(chunk)
726 record = logging.makeLogRecord(obj)
727 self.handle_log_record(record)
729 def unpickle(self, data):
730 return cPickle.loads(data)
732 def handle_log_record(self, record):
733 # If the end-of-messages sentinel is seen, tell the server to
734 # terminate.
735 if self.TCP_LOG_END in record.msg:
736 self.server.abort = 1
737 return
738 self.server.log_output += record.msg + "\n"
741 class LogRecordSocketReceiver(ThreadingTCPServer):
743 """A simple-minded TCP socket-based logging receiver suitable for test
744 purposes."""
746 allow_reuse_address = 1
747 log_output = ""
749 def __init__(self, host='localhost',
750 port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
751 handler=LogRecordStreamHandler):
752 ThreadingTCPServer.__init__(self, (host, port), handler)
753 self.abort = False
754 self.timeout = 0.1
755 self.finished = threading.Event()
757 def serve_until_stopped(self):
758 while not self.abort:
759 rd, wr, ex = select.select([self.socket.fileno()], [], [],
760 self.timeout)
761 if rd:
762 self.handle_request()
763 # Notify the main thread that we're about to exit
764 self.finished.set()
765 # close the listen socket
766 self.server_close()
769 @unittest.skipUnless(threading, 'Threading required for this test.')
770 class SocketHandlerTest(BaseTest):
772 """Test for SocketHandler objects."""
774 def setUp(self):
775 """Set up a TCP server to receive log messages, and a SocketHandler
776 pointing to that server's address and port."""
777 BaseTest.setUp(self)
778 self.tcpserver = LogRecordSocketReceiver(port=0)
779 self.port = self.tcpserver.socket.getsockname()[1]
780 self.threads = [
781 threading.Thread(target=self.tcpserver.serve_until_stopped)]
782 for thread in self.threads:
783 thread.start()
785 self.sock_hdlr = logging.handlers.SocketHandler('localhost', self.port)
786 self.sock_hdlr.setFormatter(self.root_formatter)
787 self.root_logger.removeHandler(self.root_logger.handlers[0])
788 self.root_logger.addHandler(self.sock_hdlr)
790 def tearDown(self):
791 """Shutdown the TCP server."""
792 try:
793 self.tcpserver.abort = True
794 del self.tcpserver
795 self.root_logger.removeHandler(self.sock_hdlr)
796 self.sock_hdlr.close()
797 for thread in self.threads:
798 thread.join(2.0)
799 finally:
800 BaseTest.tearDown(self)
802 def get_output(self):
803 """Get the log output as received by the TCP server."""
804 # Signal the TCP receiver and wait for it to terminate.
805 self.root_logger.critical(LogRecordStreamHandler.TCP_LOG_END)
806 self.tcpserver.finished.wait(2.0)
807 return self.tcpserver.log_output
809 def test_output(self):
810 # The log message sent to the SocketHandler is properly received.
811 logger = logging.getLogger("tcp")
812 logger.error("spam")
813 logger.debug("eggs")
814 self.assertEquals(self.get_output(), "spam\neggs\n")
817 class MemoryTest(BaseTest):
819 """Test memory persistence of logger objects."""
821 def setUp(self):
822 """Create a dict to remember potentially destroyed objects."""
823 BaseTest.setUp(self)
824 self._survivors = {}
826 def _watch_for_survival(self, *args):
827 """Watch the given objects for survival, by creating weakrefs to
828 them."""
829 for obj in args:
830 key = id(obj), repr(obj)
831 self._survivors[key] = weakref.ref(obj)
833 def _assertTruesurvival(self):
834 """Assert that all objects watched for survival have survived."""
835 # Trigger cycle breaking.
836 gc.collect()
837 dead = []
838 for (id_, repr_), ref in self._survivors.items():
839 if ref() is None:
840 dead.append(repr_)
841 if dead:
842 self.fail("%d objects should have survived "
843 "but have been destroyed: %s" % (len(dead), ", ".join(dead)))
845 def test_persistent_loggers(self):
846 # Logger objects are persistent and retain their configuration, even
847 # if visible references are destroyed.
848 self.root_logger.setLevel(logging.INFO)
849 foo = logging.getLogger("foo")
850 self._watch_for_survival(foo)
851 foo.setLevel(logging.DEBUG)
852 self.root_logger.debug(self.next_message())
853 foo.debug(self.next_message())
854 self.assert_log_lines([
855 ('foo', 'DEBUG', '2'),
857 del foo
858 # foo has survived.
859 self._assertTruesurvival()
860 # foo has retained its settings.
861 bar = logging.getLogger("foo")
862 bar.debug(self.next_message())
863 self.assert_log_lines([
864 ('foo', 'DEBUG', '2'),
865 ('foo', 'DEBUG', '3'),
869 class EncodingTest(BaseTest):
870 def test_encoding_plain_file(self):
871 # In Python 2.x, a plain file object is treated as having no encoding.
872 log = logging.getLogger("test")
873 fn = tempfile.mktemp(".log")
874 # the non-ascii data we write to the log.
875 data = "foo\x80"
876 try:
877 handler = logging.FileHandler(fn)
878 log.addHandler(handler)
879 try:
880 # write non-ascii data to the log.
881 log.warning(data)
882 finally:
883 log.removeHandler(handler)
884 handler.close()
885 # check we wrote exactly those bytes, ignoring trailing \n etc
886 f = open(fn)
887 try:
888 self.assertEqual(f.read().rstrip(), data)
889 finally:
890 f.close()
891 finally:
892 if os.path.isfile(fn):
893 os.remove(fn)
895 def test_encoding_cyrillic_unicode(self):
896 log = logging.getLogger("test")
897 #Get a message in Unicode: Do svidanya in Cyrillic (meaning goodbye)
898 message = u'\u0434\u043e \u0441\u0432\u0438\u0434\u0430\u043d\u0438\u044f'
899 #Ensure it's written in a Cyrillic encoding
900 writer_class = codecs.getwriter('cp1251')
901 writer_class.encoding = 'cp1251'
902 stream = cStringIO.StringIO()
903 writer = writer_class(stream, 'strict')
904 handler = logging.StreamHandler(writer)
905 log.addHandler(handler)
906 try:
907 log.warning(message)
908 finally:
909 log.removeHandler(handler)
910 handler.close()
911 # check we wrote exactly those bytes, ignoring trailing \n etc
912 s = stream.getvalue()
913 #Compare against what the data should be when encoded in CP-1251
914 self.assertEqual(s, '\xe4\xee \xf1\xe2\xe8\xe4\xe0\xed\xe8\xff\n')
917 class WarningsTest(BaseTest):
919 def test_warnings(self):
920 with warnings.catch_warnings():
921 logging.captureWarnings(True)
922 try:
923 warnings.filterwarnings("always", category=UserWarning)
924 file = cStringIO.StringIO()
925 h = logging.StreamHandler(file)
926 logger = logging.getLogger("py.warnings")
927 logger.addHandler(h)
928 warnings.warn("I'm warning you...")
929 logger.removeHandler(h)
930 s = file.getvalue()
931 h.close()
932 self.assertTrue(s.find("UserWarning: I'm warning you...\n") > 0)
934 #See if an explicit file uses the original implementation
935 file = cStringIO.StringIO()
936 warnings.showwarning("Explicit", UserWarning, "dummy.py", 42,
937 file, "Dummy line")
938 s = file.getvalue()
939 file.close()
940 self.assertEqual(s,
941 "dummy.py:42: UserWarning: Explicit\n Dummy line\n")
942 finally:
943 logging.captureWarnings(False)
946 def formatFunc(format, datefmt=None):
947 return logging.Formatter(format, datefmt)
949 def handlerFunc():
950 return logging.StreamHandler()
952 class CustomHandler(logging.StreamHandler):
953 pass
955 class ConfigDictTest(BaseTest):
957 """Reading logging config from a dictionary."""
959 expected_log_pat = r"^([\w]+) \+\+ ([\w]+)$"
961 # config0 is a standard configuration.
962 config0 = {
963 'version': 1,
964 'formatters': {
965 'form1' : {
966 'format' : '%(levelname)s ++ %(message)s',
969 'handlers' : {
970 'hand1' : {
971 'class' : 'logging.StreamHandler',
972 'formatter' : 'form1',
973 'level' : 'NOTSET',
974 'stream' : 'ext://sys.stdout',
977 'root' : {
978 'level' : 'WARNING',
979 'handlers' : ['hand1'],
983 # config1 adds a little to the standard configuration.
984 config1 = {
985 'version': 1,
986 'formatters': {
987 'form1' : {
988 'format' : '%(levelname)s ++ %(message)s',
991 'handlers' : {
992 'hand1' : {
993 'class' : 'logging.StreamHandler',
994 'formatter' : 'form1',
995 'level' : 'NOTSET',
996 'stream' : 'ext://sys.stdout',
999 'loggers' : {
1000 'compiler.parser' : {
1001 'level' : 'DEBUG',
1002 'handlers' : ['hand1'],
1005 'root' : {
1006 'level' : 'WARNING',
1010 # config2 has a subtle configuration error that should be reported
1011 config2 = {
1012 'version': 1,
1013 'formatters': {
1014 'form1' : {
1015 'format' : '%(levelname)s ++ %(message)s',
1018 'handlers' : {
1019 'hand1' : {
1020 'class' : 'logging.StreamHandler',
1021 'formatter' : 'form1',
1022 'level' : 'NOTSET',
1023 'stream' : 'ext://sys.stdbout',
1026 'loggers' : {
1027 'compiler.parser' : {
1028 'level' : 'DEBUG',
1029 'handlers' : ['hand1'],
1032 'root' : {
1033 'level' : 'WARNING',
1037 #As config1 but with a misspelt level on a handler
1038 config2a = {
1039 'version': 1,
1040 'formatters': {
1041 'form1' : {
1042 'format' : '%(levelname)s ++ %(message)s',
1045 'handlers' : {
1046 'hand1' : {
1047 'class' : 'logging.StreamHandler',
1048 'formatter' : 'form1',
1049 'level' : 'NTOSET',
1050 'stream' : 'ext://sys.stdout',
1053 'loggers' : {
1054 'compiler.parser' : {
1055 'level' : 'DEBUG',
1056 'handlers' : ['hand1'],
1059 'root' : {
1060 'level' : 'WARNING',
1065 #As config1 but with a misspelt level on a logger
1066 config2b = {
1067 'version': 1,
1068 'formatters': {
1069 'form1' : {
1070 'format' : '%(levelname)s ++ %(message)s',
1073 'handlers' : {
1074 'hand1' : {
1075 'class' : 'logging.StreamHandler',
1076 'formatter' : 'form1',
1077 'level' : 'NOTSET',
1078 'stream' : 'ext://sys.stdout',
1081 'loggers' : {
1082 'compiler.parser' : {
1083 'level' : 'DEBUG',
1084 'handlers' : ['hand1'],
1087 'root' : {
1088 'level' : 'WRANING',
1092 # config3 has a less subtle configuration error
1093 config3 = {
1094 'version': 1,
1095 'formatters': {
1096 'form1' : {
1097 'format' : '%(levelname)s ++ %(message)s',
1100 'handlers' : {
1101 'hand1' : {
1102 'class' : 'logging.StreamHandler',
1103 'formatter' : 'misspelled_name',
1104 'level' : 'NOTSET',
1105 'stream' : 'ext://sys.stdout',
1108 'loggers' : {
1109 'compiler.parser' : {
1110 'level' : 'DEBUG',
1111 'handlers' : ['hand1'],
1114 'root' : {
1115 'level' : 'WARNING',
1119 # config4 specifies a custom formatter class to be loaded
1120 config4 = {
1121 'version': 1,
1122 'formatters': {
1123 'form1' : {
1124 '()' : __name__ + '.ExceptionFormatter',
1125 'format' : '%(levelname)s:%(name)s:%(message)s',
1128 'handlers' : {
1129 'hand1' : {
1130 'class' : 'logging.StreamHandler',
1131 'formatter' : 'form1',
1132 'level' : 'NOTSET',
1133 'stream' : 'ext://sys.stdout',
1136 'root' : {
1137 'level' : 'NOTSET',
1138 'handlers' : ['hand1'],
1142 # As config4 but using an actual callable rather than a string
1143 config4a = {
1144 'version': 1,
1145 'formatters': {
1146 'form1' : {
1147 '()' : ExceptionFormatter,
1148 'format' : '%(levelname)s:%(name)s:%(message)s',
1150 'form2' : {
1151 '()' : __name__ + '.formatFunc',
1152 'format' : '%(levelname)s:%(name)s:%(message)s',
1154 'form3' : {
1155 '()' : formatFunc,
1156 'format' : '%(levelname)s:%(name)s:%(message)s',
1159 'handlers' : {
1160 'hand1' : {
1161 'class' : 'logging.StreamHandler',
1162 'formatter' : 'form1',
1163 'level' : 'NOTSET',
1164 'stream' : 'ext://sys.stdout',
1166 'hand2' : {
1167 '()' : handlerFunc,
1170 'root' : {
1171 'level' : 'NOTSET',
1172 'handlers' : ['hand1'],
1176 # config5 specifies a custom handler class to be loaded
1177 config5 = {
1178 'version': 1,
1179 'formatters': {
1180 'form1' : {
1181 'format' : '%(levelname)s ++ %(message)s',
1184 'handlers' : {
1185 'hand1' : {
1186 'class' : __name__ + '.CustomHandler',
1187 'formatter' : 'form1',
1188 'level' : 'NOTSET',
1189 'stream' : 'ext://sys.stdout',
1192 'loggers' : {
1193 'compiler.parser' : {
1194 'level' : 'DEBUG',
1195 'handlers' : ['hand1'],
1198 'root' : {
1199 'level' : 'WARNING',
1203 # config6 specifies a custom handler class to be loaded
1204 # but has bad arguments
1205 config6 = {
1206 'version': 1,
1207 'formatters': {
1208 'form1' : {
1209 'format' : '%(levelname)s ++ %(message)s',
1212 'handlers' : {
1213 'hand1' : {
1214 'class' : __name__ + '.CustomHandler',
1215 'formatter' : 'form1',
1216 'level' : 'NOTSET',
1217 'stream' : 'ext://sys.stdout',
1218 '9' : 'invalid parameter name',
1221 'loggers' : {
1222 'compiler.parser' : {
1223 'level' : 'DEBUG',
1224 'handlers' : ['hand1'],
1227 'root' : {
1228 'level' : 'WARNING',
1232 #config 7 does not define compiler.parser but defines compiler.lexer
1233 #so compiler.parser should be disabled after applying it
1234 config7 = {
1235 'version': 1,
1236 'formatters': {
1237 'form1' : {
1238 'format' : '%(levelname)s ++ %(message)s',
1241 'handlers' : {
1242 'hand1' : {
1243 'class' : 'logging.StreamHandler',
1244 'formatter' : 'form1',
1245 'level' : 'NOTSET',
1246 'stream' : 'ext://sys.stdout',
1249 'loggers' : {
1250 'compiler.lexer' : {
1251 'level' : 'DEBUG',
1252 'handlers' : ['hand1'],
1255 'root' : {
1256 'level' : 'WARNING',
1260 config8 = {
1261 'version': 1,
1262 'disable_existing_loggers' : False,
1263 'formatters': {
1264 'form1' : {
1265 'format' : '%(levelname)s ++ %(message)s',
1268 'handlers' : {
1269 'hand1' : {
1270 'class' : 'logging.StreamHandler',
1271 'formatter' : 'form1',
1272 'level' : 'NOTSET',
1273 'stream' : 'ext://sys.stdout',
1276 'loggers' : {
1277 'compiler' : {
1278 'level' : 'DEBUG',
1279 'handlers' : ['hand1'],
1281 'compiler.lexer' : {
1284 'root' : {
1285 'level' : 'WARNING',
1289 config9 = {
1290 'version': 1,
1291 'formatters': {
1292 'form1' : {
1293 'format' : '%(levelname)s ++ %(message)s',
1296 'handlers' : {
1297 'hand1' : {
1298 'class' : 'logging.StreamHandler',
1299 'formatter' : 'form1',
1300 'level' : 'WARNING',
1301 'stream' : 'ext://sys.stdout',
1304 'loggers' : {
1305 'compiler.parser' : {
1306 'level' : 'WARNING',
1307 'handlers' : ['hand1'],
1310 'root' : {
1311 'level' : 'NOTSET',
1315 config9a = {
1316 'version': 1,
1317 'incremental' : True,
1318 'handlers' : {
1319 'hand1' : {
1320 'level' : 'WARNING',
1323 'loggers' : {
1324 'compiler.parser' : {
1325 'level' : 'INFO',
1330 config9b = {
1331 'version': 1,
1332 'incremental' : True,
1333 'handlers' : {
1334 'hand1' : {
1335 'level' : 'INFO',
1338 'loggers' : {
1339 'compiler.parser' : {
1340 'level' : 'INFO',
1345 #As config1 but with a filter added
1346 config10 = {
1347 'version': 1,
1348 'formatters': {
1349 'form1' : {
1350 'format' : '%(levelname)s ++ %(message)s',
1353 'filters' : {
1354 'filt1' : {
1355 'name' : 'compiler.parser',
1358 'handlers' : {
1359 'hand1' : {
1360 'class' : 'logging.StreamHandler',
1361 'formatter' : 'form1',
1362 'level' : 'NOTSET',
1363 'stream' : 'ext://sys.stdout',
1364 'filters' : ['filt1'],
1367 'loggers' : {
1368 'compiler.parser' : {
1369 'level' : 'DEBUG',
1370 'filters' : ['filt1'],
1373 'root' : {
1374 'level' : 'WARNING',
1375 'handlers' : ['hand1'],
1379 #As config1 but using cfg:// references
1380 config11 = {
1381 'version': 1,
1382 'true_formatters': {
1383 'form1' : {
1384 'format' : '%(levelname)s ++ %(message)s',
1387 'handler_configs': {
1388 'hand1' : {
1389 'class' : 'logging.StreamHandler',
1390 'formatter' : 'form1',
1391 'level' : 'NOTSET',
1392 'stream' : 'ext://sys.stdout',
1395 'formatters' : 'cfg://true_formatters',
1396 'handlers' : {
1397 'hand1' : 'cfg://handler_configs[hand1]',
1399 'loggers' : {
1400 'compiler.parser' : {
1401 'level' : 'DEBUG',
1402 'handlers' : ['hand1'],
1405 'root' : {
1406 'level' : 'WARNING',
1410 #As config11 but missing the version key
1411 config12 = {
1412 'true_formatters': {
1413 'form1' : {
1414 'format' : '%(levelname)s ++ %(message)s',
1417 'handler_configs': {
1418 'hand1' : {
1419 'class' : 'logging.StreamHandler',
1420 'formatter' : 'form1',
1421 'level' : 'NOTSET',
1422 'stream' : 'ext://sys.stdout',
1425 'formatters' : 'cfg://true_formatters',
1426 'handlers' : {
1427 'hand1' : 'cfg://handler_configs[hand1]',
1429 'loggers' : {
1430 'compiler.parser' : {
1431 'level' : 'DEBUG',
1432 'handlers' : ['hand1'],
1435 'root' : {
1436 'level' : 'WARNING',
1440 #As config11 but using an unsupported version
1441 config13 = {
1442 'version': 2,
1443 'true_formatters': {
1444 'form1' : {
1445 'format' : '%(levelname)s ++ %(message)s',
1448 'handler_configs': {
1449 'hand1' : {
1450 'class' : 'logging.StreamHandler',
1451 'formatter' : 'form1',
1452 'level' : 'NOTSET',
1453 'stream' : 'ext://sys.stdout',
1456 'formatters' : 'cfg://true_formatters',
1457 'handlers' : {
1458 'hand1' : 'cfg://handler_configs[hand1]',
1460 'loggers' : {
1461 'compiler.parser' : {
1462 'level' : 'DEBUG',
1463 'handlers' : ['hand1'],
1466 'root' : {
1467 'level' : 'WARNING',
1471 def apply_config(self, conf):
1472 logging.config.dictConfig(conf)
1474 def test_config0_ok(self):
1475 # A simple config which overrides the default settings.
1476 with captured_stdout() as output:
1477 self.apply_config(self.config0)
1478 logger = logging.getLogger()
1479 # Won't output anything
1480 logger.info(self.next_message())
1481 # Outputs a message
1482 logger.error(self.next_message())
1483 self.assert_log_lines([
1484 ('ERROR', '2'),
1485 ], stream=output)
1486 # Original logger output is empty.
1487 self.assert_log_lines([])
1489 def test_config1_ok(self, config=config1):
1490 # A config defining a sub-parser as well.
1491 with captured_stdout() as output:
1492 self.apply_config(config)
1493 logger = logging.getLogger("compiler.parser")
1494 # Both will output a message
1495 logger.info(self.next_message())
1496 logger.error(self.next_message())
1497 self.assert_log_lines([
1498 ('INFO', '1'),
1499 ('ERROR', '2'),
1500 ], stream=output)
1501 # Original logger output is empty.
1502 self.assert_log_lines([])
1504 def test_config2_failure(self):
1505 # A simple config which overrides the default settings.
1506 self.assertRaises(StandardError, self.apply_config, self.config2)
1508 def test_config2a_failure(self):
1509 # A simple config which overrides the default settings.
1510 self.assertRaises(StandardError, self.apply_config, self.config2a)
1512 def test_config2b_failure(self):
1513 # A simple config which overrides the default settings.
1514 self.assertRaises(StandardError, self.apply_config, self.config2b)
1516 def test_config3_failure(self):
1517 # A simple config which overrides the default settings.
1518 self.assertRaises(StandardError, self.apply_config, self.config3)
1520 def test_config4_ok(self):
1521 # A config specifying a custom formatter class.
1522 with captured_stdout() as output:
1523 self.apply_config(self.config4)
1524 #logger = logging.getLogger()
1525 try:
1526 raise RuntimeError()
1527 except RuntimeError:
1528 logging.exception("just testing")
1529 sys.stdout.seek(0)
1530 self.assertEquals(output.getvalue(),
1531 "ERROR:root:just testing\nGot a [RuntimeError]\n")
1532 # Original logger output is empty
1533 self.assert_log_lines([])
1535 def test_config4a_ok(self):
1536 # A config specifying a custom formatter class.
1537 with captured_stdout() as output:
1538 self.apply_config(self.config4a)
1539 #logger = logging.getLogger()
1540 try:
1541 raise RuntimeError()
1542 except RuntimeError:
1543 logging.exception("just testing")
1544 sys.stdout.seek(0)
1545 self.assertEquals(output.getvalue(),
1546 "ERROR:root:just testing\nGot a [RuntimeError]\n")
1547 # Original logger output is empty
1548 self.assert_log_lines([])
1550 def test_config5_ok(self):
1551 self.test_config1_ok(config=self.config5)
1553 def test_config6_failure(self):
1554 self.assertRaises(StandardError, self.apply_config, self.config6)
1556 def test_config7_ok(self):
1557 with captured_stdout() as output:
1558 self.apply_config(self.config1)
1559 logger = logging.getLogger("compiler.parser")
1560 # Both will output a message
1561 logger.info(self.next_message())
1562 logger.error(self.next_message())
1563 self.assert_log_lines([
1564 ('INFO', '1'),
1565 ('ERROR', '2'),
1566 ], stream=output)
1567 # Original logger output is empty.
1568 self.assert_log_lines([])
1569 with captured_stdout() as output:
1570 self.apply_config(self.config7)
1571 logger = logging.getLogger("compiler.parser")
1572 self.assertTrue(logger.disabled)
1573 logger = logging.getLogger("compiler.lexer")
1574 # Both will output a message
1575 logger.info(self.next_message())
1576 logger.error(self.next_message())
1577 self.assert_log_lines([
1578 ('INFO', '3'),
1579 ('ERROR', '4'),
1580 ], stream=output)
1581 # Original logger output is empty.
1582 self.assert_log_lines([])
1584 #Same as test_config_7_ok but don't disable old loggers.
1585 def test_config_8_ok(self):
1586 with captured_stdout() as output:
1587 self.apply_config(self.config1)
1588 logger = logging.getLogger("compiler.parser")
1589 # Both will output a message
1590 logger.info(self.next_message())
1591 logger.error(self.next_message())
1592 self.assert_log_lines([
1593 ('INFO', '1'),
1594 ('ERROR', '2'),
1595 ], stream=output)
1596 # Original logger output is empty.
1597 self.assert_log_lines([])
1598 with captured_stdout() as output:
1599 self.apply_config(self.config8)
1600 logger = logging.getLogger("compiler.parser")
1601 self.assertFalse(logger.disabled)
1602 # Both will output a message
1603 logger.info(self.next_message())
1604 logger.error(self.next_message())
1605 logger = logging.getLogger("compiler.lexer")
1606 # Both will output a message
1607 logger.info(self.next_message())
1608 logger.error(self.next_message())
1609 self.assert_log_lines([
1610 ('INFO', '3'),
1611 ('ERROR', '4'),
1612 ('INFO', '5'),
1613 ('ERROR', '6'),
1614 ], stream=output)
1615 # Original logger output is empty.
1616 self.assert_log_lines([])
1618 def test_config_9_ok(self):
1619 with captured_stdout() as output:
1620 self.apply_config(self.config9)
1621 logger = logging.getLogger("compiler.parser")
1622 #Nothing will be output since both handler and logger are set to WARNING
1623 logger.info(self.next_message())
1624 self.assert_log_lines([], stream=output)
1625 self.apply_config(self.config9a)
1626 #Nothing will be output since both handler is still set to WARNING
1627 logger.info(self.next_message())
1628 self.assert_log_lines([], stream=output)
1629 self.apply_config(self.config9b)
1630 #Message should now be output
1631 logger.info(self.next_message())
1632 self.assert_log_lines([
1633 ('INFO', '3'),
1634 ], stream=output)
1636 def test_config_10_ok(self):
1637 with captured_stdout() as output:
1638 self.apply_config(self.config10)
1639 logger = logging.getLogger("compiler.parser")
1640 logger.warning(self.next_message())
1641 logger = logging.getLogger('compiler')
1642 #Not output, because filtered
1643 logger.warning(self.next_message())
1644 logger = logging.getLogger('compiler.lexer')
1645 #Not output, because filtered
1646 logger.warning(self.next_message())
1647 logger = logging.getLogger("compiler.parser.codegen")
1648 #Output, as not filtered
1649 logger.error(self.next_message())
1650 self.assert_log_lines([
1651 ('WARNING', '1'),
1652 ('ERROR', '4'),
1653 ], stream=output)
1655 def test_config11_ok(self):
1656 self.test_config1_ok(self.config11)
1658 def test_config12_failure(self):
1659 self.assertRaises(StandardError, self.apply_config, self.config12)
1661 def test_config13_failure(self):
1662 self.assertRaises(StandardError, self.apply_config, self.config13)
1664 @unittest.skipUnless(threading, 'listen() needs threading to work')
1665 def setup_via_listener(self, text):
1666 # Ask for a randomly assigned port (by using port 0)
1667 t = logging.config.listen(0)
1668 t.start()
1669 t.ready.wait()
1670 # Now get the port allocated
1671 port = t.port
1672 t.ready.clear()
1673 try:
1674 sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
1675 sock.settimeout(2.0)
1676 sock.connect(('localhost', port))
1678 slen = struct.pack('>L', len(text))
1679 s = slen + text
1680 sentsofar = 0
1681 left = len(s)
1682 while left > 0:
1683 sent = sock.send(s[sentsofar:])
1684 sentsofar += sent
1685 left -= sent
1686 sock.close()
1687 finally:
1688 t.ready.wait(2.0)
1689 logging.config.stopListening()
1690 t.join(2.0)
1692 def test_listen_config_10_ok(self):
1693 with captured_stdout() as output:
1694 self.setup_via_listener(json.dumps(self.config10))
1695 logger = logging.getLogger("compiler.parser")
1696 logger.warning(self.next_message())
1697 logger = logging.getLogger('compiler')
1698 #Not output, because filtered
1699 logger.warning(self.next_message())
1700 logger = logging.getLogger('compiler.lexer')
1701 #Not output, because filtered
1702 logger.warning(self.next_message())
1703 logger = logging.getLogger("compiler.parser.codegen")
1704 #Output, as not filtered
1705 logger.error(self.next_message())
1706 self.assert_log_lines([
1707 ('WARNING', '1'),
1708 ('ERROR', '4'),
1709 ], stream=output)
1711 def test_listen_config_1_ok(self):
1712 with captured_stdout() as output:
1713 self.setup_via_listener(textwrap.dedent(ConfigFileTest.config1))
1714 logger = logging.getLogger("compiler.parser")
1715 # Both will output a message
1716 logger.info(self.next_message())
1717 logger.error(self.next_message())
1718 self.assert_log_lines([
1719 ('INFO', '1'),
1720 ('ERROR', '2'),
1721 ], stream=output)
1722 # Original logger output is empty.
1723 self.assert_log_lines([])
1726 class ManagerTest(BaseTest):
1727 def test_manager_loggerclass(self):
1728 logged = []
1730 class MyLogger(logging.Logger):
1731 def _log(self, level, msg, args, exc_info=None, extra=None):
1732 logged.append(msg)
1734 man = logging.Manager(None)
1735 self.assertRaises(TypeError, man.setLoggerClass, int)
1736 man.setLoggerClass(MyLogger)
1737 logger = man.getLogger('test')
1738 logger.warning('should appear in logged')
1739 logging.warning('should not appear in logged')
1741 self.assertEqual(logged, ['should appear in logged'])
1744 class ChildLoggerTest(BaseTest):
1745 def test_child_loggers(self):
1746 r = logging.getLogger()
1747 l1 = logging.getLogger('abc')
1748 l2 = logging.getLogger('def.ghi')
1749 c1 = r.getChild('xyz')
1750 c2 = r.getChild('uvw.xyz')
1751 self.assertTrue(c1 is logging.getLogger('xyz'))
1752 self.assertTrue(c2 is logging.getLogger('uvw.xyz'))
1753 c1 = l1.getChild('def')
1754 c2 = c1.getChild('ghi')
1755 c3 = l1.getChild('def.ghi')
1756 self.assertTrue(c1 is logging.getLogger('abc.def'))
1757 self.assertTrue(c2 is logging.getLogger('abc.def.ghi'))
1758 self.assertTrue(c2 is c3)
1761 # Set the locale to the platform-dependent default. I have no idea
1762 # why the test does this, but in any case we save the current locale
1763 # first and restore it at the end.
1764 @run_with_locale('LC_ALL', '')
1765 def test_main():
1766 run_unittest(BuiltinLevelsTest, BasicFilterTest,
1767 CustomLevelsAndFiltersTest, MemoryHandlerTest,
1768 ConfigFileTest, SocketHandlerTest, MemoryTest,
1769 EncodingTest, WarningsTest, ConfigDictTest, ManagerTest,
1770 ChildLoggerTest)
1772 if __name__ == "__main__":
1773 test_main()