home *** CD-ROM | disk | FTP | other *** search
/ Maximum CD 2011 July / maximum-cd-2011-07.iso / DiscContents / LibO_3.3.2_Win_x86_install_multi.exe / libreoffice1.cab / test_logging.py < prev    next >
Encoding:
Python Source  |  2011-03-15  |  27.6 KB  |  900 lines
  1. #!/usr/bin/env python
  2. #
  3. # Copyright 2001-2004 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-2002 Vinay Sajip. All Rights Reserved.
  22. """
  23.  
  24. import logging
  25. import logging.handlers
  26. import logging.config
  27.  
  28. import copy
  29. import cPickle
  30. import cStringIO
  31. import gc
  32. import os
  33. import re
  34. import select
  35. import socket
  36. from SocketServer import ThreadingTCPServer, StreamRequestHandler
  37. import string
  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 threading
  44. import time
  45. import types
  46. import unittest
  47. import weakref
  48.  
  49.  
  50. class BaseTest(unittest.TestCase):
  51.  
  52.     """Base class for logging tests."""
  53.  
  54.     log_format = "%(name)s -> %(levelname)s: %(message)s"
  55.     expected_log_pat = r"^([\w.]+) -> ([\w]+): ([\d]+)$"
  56.     message_num = 0
  57.  
  58.     def setUp(self):
  59.         """Setup the default logging stream to an internal StringIO instance,
  60.         so that we can examine log output as we want."""
  61.         logger_dict = logging.getLogger().manager.loggerDict
  62.         logging._acquireLock()
  63.         try:
  64.             self.saved_handlers = logging._handlers.copy()
  65.             self.saved_handler_list = logging._handlerList[:]
  66.             self.saved_loggers = logger_dict.copy()
  67.             self.saved_level_names = logging._levelNames.copy()
  68.         finally:
  69.             logging._releaseLock()
  70.  
  71.         self.root_logger = logging.getLogger("")
  72.         self.original_logging_level = self.root_logger.getEffectiveLevel()
  73.  
  74.         self.stream = cStringIO.StringIO()
  75.         self.root_logger.setLevel(logging.DEBUG)
  76.         self.root_hdlr = logging.StreamHandler(self.stream)
  77.         self.root_formatter = logging.Formatter(self.log_format)
  78.         self.root_hdlr.setFormatter(self.root_formatter)
  79.         self.root_logger.addHandler(self.root_hdlr)
  80.  
  81.     def tearDown(self):
  82.         """Remove our logging stream, and restore the original logging
  83.         level."""
  84.         self.stream.close()
  85.         self.root_logger.removeHandler(self.root_hdlr)
  86.         self.root_logger.setLevel(self.original_logging_level)
  87.         logging._acquireLock()
  88.         try:
  89.             logging._levelNames.clear()
  90.             logging._levelNames.update(self.saved_level_names)
  91.             logging._handlers.clear()
  92.             logging._handlers.update(self.saved_handlers)
  93.             logging._handlerList[:] = self.saved_handler_list
  94.             loggerDict = logging.getLogger().manager.loggerDict
  95.             loggerDict.clear()
  96.             loggerDict.update(self.saved_loggers)
  97.         finally:
  98.             logging._releaseLock()
  99.  
  100.     def assert_log_lines(self, expected_values, stream=None):
  101.         """Match the collected log lines against the regular expression
  102.         self.expected_log_pat, and compare the extracted group values to
  103.         the expected_values list of tuples."""
  104.         stream = stream or self.stream
  105.         pat = re.compile(self.expected_log_pat)
  106.         try:
  107.             stream.reset()
  108.             actual_lines = stream.readlines()
  109.         except AttributeError:
  110.             # StringIO.StringIO lacks a reset() method.
  111.             actual_lines = stream.getvalue().splitlines()
  112.         self.assertEquals(len(actual_lines), len(expected_values))
  113.         for actual, expected in zip(actual_lines, expected_values):
  114.             match = pat.search(actual)
  115.             if not match:
  116.                 self.fail("Log line does not match expected pattern:\n" +
  117.                             actual)
  118.             self.assertEquals(tuple(match.groups()), expected)
  119.         s = stream.read()
  120.         if s:
  121.             self.fail("Remaining output at end of log stream:\n" + s)
  122.  
  123.     def next_message(self):
  124.         """Generate a message consisting solely of an auto-incrementing
  125.         integer."""
  126.         self.message_num += 1
  127.         return "%d" % self.message_num
  128.  
  129.  
  130. class BuiltinLevelsTest(BaseTest):
  131.     """Test builtin levels and their inheritance."""
  132.  
  133.     def test_flat(self):
  134.         #Logging levels in a flat logger namespace.
  135.         m = self.next_message
  136.  
  137.         ERR = logging.getLogger("ERR")
  138.         ERR.setLevel(logging.ERROR)
  139.         INF = logging.getLogger("INF")
  140.         INF.setLevel(logging.INFO)
  141.         DEB = logging.getLogger("DEB")
  142.         DEB.setLevel(logging.DEBUG)
  143.  
  144.         # These should log.
  145.         ERR.log(logging.CRITICAL, m())
  146.         ERR.error(m())
  147.  
  148.         INF.log(logging.CRITICAL, m())
  149.         INF.error(m())
  150.         INF.warn(m())
  151.         INF.info(m())
  152.  
  153.         DEB.log(logging.CRITICAL, m())
  154.         DEB.error(m())
  155.         DEB.warn (m())
  156.         DEB.info (m())
  157.         DEB.debug(m())
  158.  
  159.         # These should not log.
  160.         ERR.warn(m())
  161.         ERR.info(m())
  162.         ERR.debug(m())
  163.  
  164.         INF.debug(m())
  165.  
  166.         self.assert_log_lines([
  167.             ('ERR', 'CRITICAL', '1'),
  168.             ('ERR', 'ERROR', '2'),
  169.             ('INF', 'CRITICAL', '3'),
  170.             ('INF', 'ERROR', '4'),
  171.             ('INF', 'WARNING', '5'),
  172.             ('INF', 'INFO', '6'),
  173.             ('DEB', 'CRITICAL', '7'),
  174.             ('DEB', 'ERROR', '8'),
  175.             ('DEB', 'WARNING', '9'),
  176.             ('DEB', 'INFO', '10'),
  177.             ('DEB', 'DEBUG', '11'),
  178.         ])
  179.  
  180.     def test_nested_explicit(self):
  181.         # Logging levels in a nested namespace, all explicitly set.
  182.         m = self.next_message
  183.  
  184.         INF = logging.getLogger("INF")
  185.         INF.setLevel(logging.INFO)
  186.         INF_ERR  = logging.getLogger("INF.ERR")
  187.         INF_ERR.setLevel(logging.ERROR)
  188.  
  189.         # These should log.
  190.         INF_ERR.log(logging.CRITICAL, m())
  191.         INF_ERR.error(m())
  192.  
  193.         # These should not log.
  194.         INF_ERR.warn(m())
  195.         INF_ERR.info(m())
  196.         INF_ERR.debug(m())
  197.  
  198.         self.assert_log_lines([
  199.             ('INF.ERR', 'CRITICAL', '1'),
  200.             ('INF.ERR', 'ERROR', '2'),
  201.         ])
  202.  
  203.     def test_nested_inherited(self):
  204.         #Logging levels in a nested namespace, inherited from parent loggers.
  205.         m = self.next_message
  206.  
  207.         INF = logging.getLogger("INF")
  208.         INF.setLevel(logging.INFO)
  209.         INF_ERR  = logging.getLogger("INF.ERR")
  210.         INF_ERR.setLevel(logging.ERROR)
  211.         INF_UNDEF = logging.getLogger("INF.UNDEF")
  212.         INF_ERR_UNDEF = logging.getLogger("INF.ERR.UNDEF")
  213.         UNDEF = logging.getLogger("UNDEF")
  214.  
  215.         # These should log.
  216.         INF_UNDEF.log(logging.CRITICAL, m())
  217.         INF_UNDEF.error(m())
  218.         INF_UNDEF.warn(m())
  219.         INF_UNDEF.info(m())
  220.         INF_ERR_UNDEF.log(logging.CRITICAL, m())
  221.         INF_ERR_UNDEF.error(m())
  222.  
  223.         # These should not log.
  224.         INF_UNDEF.debug(m())
  225.         INF_ERR_UNDEF.warn(m())
  226.         INF_ERR_UNDEF.info(m())
  227.         INF_ERR_UNDEF.debug(m())
  228.  
  229.         self.assert_log_lines([
  230.             ('INF.UNDEF', 'CRITICAL', '1'),
  231.             ('INF.UNDEF', 'ERROR', '2'),
  232.             ('INF.UNDEF', 'WARNING', '3'),
  233.             ('INF.UNDEF', 'INFO', '4'),
  234.             ('INF.ERR.UNDEF', 'CRITICAL', '5'),
  235.             ('INF.ERR.UNDEF', 'ERROR', '6'),
  236.         ])
  237.  
  238.     def test_nested_with_virtual_parent(self):
  239.         # Logging levels when some parent does not exist yet.
  240.         m = self.next_message
  241.  
  242.         INF = logging.getLogger("INF")
  243.         GRANDCHILD = logging.getLogger("INF.BADPARENT.UNDEF")
  244.         CHILD = logging.getLogger("INF.BADPARENT")
  245.         INF.setLevel(logging.INFO)
  246.  
  247.         # These should log.
  248.         GRANDCHILD.log(logging.FATAL, m())
  249.         GRANDCHILD.info(m())
  250.         CHILD.log(logging.FATAL, m())
  251.         CHILD.info(m())
  252.  
  253.         # These should not log.
  254.         GRANDCHILD.debug(m())
  255.         CHILD.debug(m())
  256.  
  257.         self.assert_log_lines([
  258.             ('INF.BADPARENT.UNDEF', 'CRITICAL', '1'),
  259.             ('INF.BADPARENT.UNDEF', 'INFO', '2'),
  260.             ('INF.BADPARENT', 'CRITICAL', '3'),
  261.             ('INF.BADPARENT', 'INFO', '4'),
  262.         ])
  263.  
  264.  
  265. class BasicFilterTest(BaseTest):
  266.  
  267.     """Test the bundled Filter class."""
  268.  
  269.     def test_filter(self):
  270.         # Only messages satisfying the specified criteria pass through the
  271.         #  filter.
  272.         filter_ = logging.Filter("spam.eggs")
  273.         handler = self.root_logger.handlers[0]
  274.         try:
  275.             handler.addFilter(filter_)
  276.             spam = logging.getLogger("spam")
  277.             spam_eggs = logging.getLogger("spam.eggs")
  278.             spam_eggs_fish = logging.getLogger("spam.eggs.fish")
  279.             spam_bakedbeans = logging.getLogger("spam.bakedbeans")
  280.  
  281.             spam.info(self.next_message())
  282.             spam_eggs.info(self.next_message())  # Good.
  283.             spam_eggs_fish.info(self.next_message())  # Good.
  284.             spam_bakedbeans.info(self.next_message())
  285.  
  286.             self.assert_log_lines([
  287.                 ('spam.eggs', 'INFO', '2'),
  288.                 ('spam.eggs.fish', 'INFO', '3'),
  289.             ])
  290.         finally:
  291.             handler.removeFilter(filter_)
  292.  
  293.  
  294. #
  295. #   First, we define our levels. There can be as many as you want - the only
  296. #     limitations are that they should be integers, the lowest should be > 0 and
  297. #   larger values mean less information being logged. If you need specific
  298. #   level values which do not fit into these limitations, you can use a
  299. #   mapping dictionary to convert between your application levels and the
  300. #   logging system.
  301. #
  302. SILENT      = 120
  303. TACITURN    = 119
  304. TERSE       = 118
  305. EFFUSIVE    = 117
  306. SOCIABLE    = 116
  307. VERBOSE     = 115
  308. TALKATIVE   = 114
  309. GARRULOUS   = 113
  310. CHATTERBOX  = 112
  311. BORING      = 111
  312.  
  313. LEVEL_RANGE = range(BORING, SILENT + 1)
  314.  
  315. #
  316. #   Next, we define names for our levels. You don't need to do this - in which
  317. #   case the system will use "Level n" to denote the text for the level.
  318. #
  319. my_logging_levels = {
  320.     SILENT      : 'Silent',
  321.     TACITURN    : 'Taciturn',
  322.     TERSE       : 'Terse',
  323.     EFFUSIVE    : 'Effusive',
  324.     SOCIABLE    : 'Sociable',
  325.     VERBOSE     : 'Verbose',
  326.     TALKATIVE   : 'Talkative',
  327.     GARRULOUS   : 'Garrulous',
  328.     CHATTERBOX  : 'Chatterbox',
  329.     BORING      : 'Boring',
  330. }
  331.  
  332. class GarrulousFilter(logging.Filter):
  333.  
  334.     """A filter which blocks garrulous messages."""
  335.  
  336.     def filter(self, record):
  337.         return record.levelno != GARRULOUS
  338.  
  339. class VerySpecificFilter(logging.Filter):
  340.  
  341.     """A filter which blocks sociable and taciturn messages."""
  342.  
  343.     def filter(self, record):
  344.         return record.levelno not in [SOCIABLE, TACITURN]
  345.  
  346.  
  347. class CustomLevelsAndFiltersTest(BaseTest):
  348.  
  349.     """Test various filtering possibilities with custom logging levels."""
  350.  
  351.     # Skip the logger name group.
  352.     expected_log_pat = r"^[\w.]+ -> ([\w]+): ([\d]+)$"
  353.  
  354.     def setUp(self):
  355.         BaseTest.setUp(self)
  356.         for k, v in my_logging_levels.items():
  357.             logging.addLevelName(k, v)
  358.  
  359.     def log_at_all_levels(self, logger):
  360.         for lvl in LEVEL_RANGE:
  361.             logger.log(lvl, self.next_message())
  362.  
  363.     def test_logger_filter(self):
  364.         # Filter at logger level.
  365.         self.root_logger.setLevel(VERBOSE)
  366.         # Levels >= 'Verbose' are good.
  367.         self.log_at_all_levels(self.root_logger)
  368.         self.assert_log_lines([
  369.             ('Verbose', '5'),
  370.             ('Sociable', '6'),
  371.             ('Effusive', '7'),
  372.             ('Terse', '8'),
  373.             ('Taciturn', '9'),
  374.             ('Silent', '10'),
  375.         ])
  376.  
  377.     def test_handler_filter(self):
  378.         # Filter at handler level.
  379.         self.root_logger.handlers[0].setLevel(SOCIABLE)
  380.         try:
  381.             # Levels >= 'Sociable' are good.
  382.             self.log_at_all_levels(self.root_logger)
  383.             self.assert_log_lines([
  384.                 ('Sociable', '6'),
  385.                 ('Effusive', '7'),
  386.                 ('Terse', '8'),
  387.                 ('Taciturn', '9'),
  388.                 ('Silent', '10'),
  389.             ])
  390.         finally:
  391.             self.root_logger.handlers[0].setLevel(logging.NOTSET)
  392.  
  393.     def test_specific_filters(self):
  394.         # Set a specific filter object on the handler, and then add another
  395.         #  filter object on the logger itself.
  396.         handler = self.root_logger.handlers[0]
  397.         specific_filter = None
  398.         garr = GarrulousFilter()
  399.         handler.addFilter(garr)
  400.         try:
  401.             self.log_at_all_levels(self.root_logger)
  402.             first_lines = [
  403.                 # Notice how 'Garrulous' is missing
  404.                 ('Boring', '1'),
  405.                 ('Chatterbox', '2'),
  406.                 ('Talkative', '4'),
  407.                 ('Verbose', '5'),
  408.                 ('Sociable', '6'),
  409.                 ('Effusive', '7'),
  410.                 ('Terse', '8'),
  411.                 ('Taciturn', '9'),
  412.                 ('Silent', '10'),
  413.             ]
  414.             self.assert_log_lines(first_lines)
  415.  
  416.             specific_filter = VerySpecificFilter()
  417.             self.root_logger.addFilter(specific_filter)
  418.             self.log_at_all_levels(self.root_logger)
  419.             self.assert_log_lines(first_lines + [
  420.                 # Not only 'Garrulous' is still missing, but also 'Sociable'
  421.                 # and 'Taciturn'
  422.                 ('Boring', '11'),
  423.                 ('Chatterbox', '12'),
  424.                 ('Talkative', '14'),
  425.                 ('Verbose', '15'),
  426.                 ('Effusive', '17'),
  427.                 ('Terse', '18'),
  428.                 ('Silent', '20'),
  429.         ])
  430.         finally:
  431.             if specific_filter:
  432.                 self.root_logger.removeFilter(specific_filter)
  433.             handler.removeFilter(garr)
  434.  
  435.  
  436. class MemoryHandlerTest(BaseTest):
  437.  
  438.     """Tests for the MemoryHandler."""
  439.  
  440.     # Do not bother with a logger name group.
  441.     expected_log_pat = r"^[\w.]+ -> ([\w]+): ([\d]+)$"
  442.  
  443.     def setUp(self):
  444.         BaseTest.setUp(self)
  445.         self.mem_hdlr = logging.handlers.MemoryHandler(10, logging.WARNING,
  446.                                                         self.root_hdlr)
  447.         self.mem_logger = logging.getLogger('mem')
  448.         self.mem_logger.propagate = 0
  449.         self.mem_logger.addHandler(self.mem_hdlr)
  450.  
  451.     def tearDown(self):
  452.         self.mem_hdlr.close()
  453.         BaseTest.tearDown(self)
  454.  
  455.     def test_flush(self):
  456.         # The memory handler flushes to its target handler based on specific
  457.         #  criteria (message count and message level).
  458.         self.mem_logger.debug(self.next_message())
  459.         self.assert_log_lines([])
  460.         self.mem_logger.info(self.next_message())
  461.         self.assert_log_lines([])
  462.         # This will flush because the level is >= logging.WARNING
  463.         self.mem_logger.warn(self.next_message())
  464.         lines = [
  465.             ('DEBUG', '1'),
  466.             ('INFO', '2'),
  467.             ('WARNING', '3'),
  468.         ]
  469.         self.assert_log_lines(lines)
  470.         for n in (4, 14):
  471.             for i in range(9):
  472.                 self.mem_logger.debug(self.next_message())
  473.             self.assert_log_lines(lines)
  474.             # This will flush because it's the 10th message since the last
  475.             #  flush.
  476.             self.mem_logger.debug(self.next_message())
  477.             lines = lines + [('DEBUG', str(i)) for i in range(n, n + 10)]
  478.             self.assert_log_lines(lines)
  479.  
  480.         self.mem_logger.debug(self.next_message())
  481.         self.assert_log_lines(lines)
  482.  
  483.  
  484. class ExceptionFormatter(logging.Formatter):
  485.     """A special exception formatter."""
  486.     def formatException(self, ei):
  487.         return "Got a [%s]" % ei[0].__name__
  488.  
  489.  
  490. class ConfigFileTest(BaseTest):
  491.  
  492.     """Reading logging config from a .ini-style config file."""
  493.  
  494.     expected_log_pat = r"^([\w]+) \+\+ ([\w]+)$"
  495.  
  496.     # config0 is a standard configuration.
  497.     config0 = """
  498.     [loggers]
  499.     keys=root
  500.  
  501.     [handlers]
  502.     keys=hand1
  503.  
  504.     [formatters]
  505.     keys=form1
  506.  
  507.     [logger_root]
  508.     level=WARNING
  509.     handlers=hand1
  510.  
  511.     [handler_hand1]
  512.     class=StreamHandler
  513.     level=NOTSET
  514.     formatter=form1
  515.     args=(sys.stdout,)
  516.  
  517.     [formatter_form1]
  518.     format=%(levelname)s ++ %(message)s
  519.     datefmt=
  520.     """
  521.  
  522.     # config1 adds a little to the standard configuration.
  523.     config1 = """
  524.     [loggers]
  525.     keys=root,parser
  526.  
  527.     [handlers]
  528.     keys=hand1
  529.  
  530.     [formatters]
  531.     keys=form1
  532.  
  533.     [logger_root]
  534.     level=WARNING
  535.     handlers=
  536.  
  537.     [logger_parser]
  538.     level=DEBUG
  539.     handlers=hand1
  540.     propagate=1
  541.     qualname=compiler.parser
  542.  
  543.     [handler_hand1]
  544.     class=StreamHandler
  545.     level=NOTSET
  546.     formatter=form1
  547.     args=(sys.stdout,)
  548.  
  549.     [formatter_form1]
  550.     format=%(levelname)s ++ %(message)s
  551.     datefmt=
  552.     """
  553.  
  554.     # config2 has a subtle configuration error that should be reported
  555.     config2 = config1.replace("sys.stdout", "sys.stbout")
  556.  
  557.     # config3 has a less subtle configuration error
  558.     config3 = config1.replace("formatter=form1", "formatter=misspelled_name")
  559.  
  560.     # config4 specifies a custom formatter class to be loaded
  561.     config4 = """
  562.     [loggers]
  563.     keys=root
  564.  
  565.     [handlers]
  566.     keys=hand1
  567.  
  568.     [formatters]
  569.     keys=form1
  570.  
  571.     [logger_root]
  572.     level=NOTSET
  573.     handlers=hand1
  574.  
  575.     [handler_hand1]
  576.     class=StreamHandler
  577.     level=NOTSET
  578.     formatter=form1
  579.     args=(sys.stdout,)
  580.  
  581.     [formatter_form1]
  582.     class=""" + __name__ + """.ExceptionFormatter
  583.     format=%(levelname)s:%(name)s:%(message)s
  584.     datefmt=
  585.     """
  586.  
  587.     # config5 specifies a custom handler class to be loaded
  588.     config5 = config1.replace('class=StreamHandler', 'class=logging.StreamHandler')
  589.  
  590.     # config6 uses ', ' delimiters in the handlers and formatters sections
  591.     config6 = """
  592.     [loggers]
  593.     keys=root,parser
  594.  
  595.     [handlers]
  596.     keys=hand1, hand2
  597.  
  598.     [formatters]
  599.     keys=form1, form2
  600.  
  601.     [logger_root]
  602.     level=WARNING
  603.     handlers=
  604.  
  605.     [logger_parser]
  606.     level=DEBUG
  607.     handlers=hand1
  608.     propagate=1
  609.     qualname=compiler.parser
  610.  
  611.     [handler_hand1]
  612.     class=StreamHandler
  613.     level=NOTSET
  614.     formatter=form1
  615.     args=(sys.stdout,)
  616.  
  617.     [handler_hand2]
  618.     class=StreamHandler
  619.     level=NOTSET
  620.     formatter=form1
  621.     args=(sys.stderr,)
  622.  
  623.     [formatter_form1]
  624.     format=%(levelname)s ++ %(message)s
  625.     datefmt=
  626.  
  627.     [formatter_form2]
  628.     format=%(message)s
  629.     datefmt=
  630.     """
  631.  
  632.     def apply_config(self, conf):
  633.         try:
  634.             fn = tempfile.mktemp(".ini")
  635.             f = open(fn, "w")
  636.             f.write(textwrap.dedent(conf))
  637.             f.close()
  638.             logging.config.fileConfig(fn)
  639.         finally:
  640.             os.remove(fn)
  641.  
  642.     def test_config0_ok(self):
  643.         # A simple config file which overrides the default settings.
  644.         with captured_stdout() as output:
  645.             self.apply_config(self.config0)
  646.             logger = logging.getLogger()
  647.             # Won't output anything
  648.             logger.info(self.next_message())
  649.             # Outputs a message
  650.             logger.error(self.next_message())
  651.             self.assert_log_lines([
  652.                 ('ERROR', '2'),
  653.             ], stream=output)
  654.             # Original logger output is empty.
  655.             self.assert_log_lines([])
  656.  
  657.     def test_config1_ok(self, config=config1):
  658.         # A config file defining a sub-parser as well.
  659.         with captured_stdout() as output:
  660.             self.apply_config(config)
  661.             logger = logging.getLogger("compiler.parser")
  662.             # Both will output a message
  663.             logger.info(self.next_message())
  664.             logger.error(self.next_message())
  665.             self.assert_log_lines([
  666.                 ('INFO', '1'),
  667.                 ('ERROR', '2'),
  668.             ], stream=output)
  669.             # Original logger output is empty.
  670.             self.assert_log_lines([])
  671.  
  672.     def test_config2_failure(self):
  673.         # A simple config file which overrides the default settings.
  674.         self.assertRaises(StandardError, self.apply_config, self.config2)
  675.  
  676.     def test_config3_failure(self):
  677.         # A simple config file which overrides the default settings.
  678.         self.assertRaises(StandardError, self.apply_config, self.config3)
  679.  
  680.     def test_config4_ok(self):
  681.         # A config file specifying a custom formatter class.
  682.         with captured_stdout() as output:
  683.             self.apply_config(self.config4)
  684.             logger = logging.getLogger()
  685.             try:
  686.                 raise RuntimeError()
  687.             except RuntimeError:
  688.                 logging.exception("just testing")
  689.             sys.stdout.seek(0)
  690.             self.assertEquals(output.getvalue(),
  691.                 "ERROR:root:just testing\nGot a [RuntimeError]\n")
  692.             # Original logger output is empty
  693.             self.assert_log_lines([])
  694.  
  695.     def test_config5_ok(self):
  696.         self.test_config1_ok(config=self.config5)
  697.  
  698.     def test_config6_ok(self):
  699.         self.test_config1_ok(config=self.config6)
  700.  
  701. class LogRecordStreamHandler(StreamRequestHandler):
  702.  
  703.     """Handler for a streaming logging request. It saves the log message in the
  704.     TCP server's 'log_output' attribute."""
  705.  
  706.     TCP_LOG_END = "!!!END!!!"
  707.  
  708.     def handle(self):
  709.         """Handle multiple requests - each expected to be of 4-byte length,
  710.         followed by the LogRecord in pickle format. Logs the record
  711.         according to whatever policy is configured locally."""
  712.         while True:
  713.             chunk = self.connection.recv(4)
  714.             if len(chunk) < 4:
  715.                 break
  716.             slen = struct.unpack(">L", chunk)[0]
  717.             chunk = self.connection.recv(slen)
  718.             while len(chunk) < slen:
  719.                 chunk = chunk + self.connection.recv(slen - len(chunk))
  720.             obj = self.unpickle(chunk)
  721.             record = logging.makeLogRecord(obj)
  722.             self.handle_log_record(record)
  723.  
  724.     def unpickle(self, data):
  725.         return cPickle.loads(data)
  726.  
  727.     def handle_log_record(self, record):
  728.         # If the end-of-messages sentinel is seen, tell the server to
  729.         #  terminate.
  730.         if self.TCP_LOG_END in record.msg:
  731.             self.server.abort = 1
  732.             return
  733.         self.server.log_output += record.msg + "\n"
  734.  
  735.  
  736. class LogRecordSocketReceiver(ThreadingTCPServer):
  737.  
  738.     """A simple-minded TCP socket-based logging receiver suitable for test
  739.     purposes."""
  740.  
  741.     allow_reuse_address = 1
  742.     log_output = ""
  743.  
  744.     def __init__(self, host='localhost',
  745.                              port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
  746.                      handler=LogRecordStreamHandler):
  747.         ThreadingTCPServer.__init__(self, (host, port), handler)
  748.         self.abort = False
  749.         self.timeout = 0.1
  750.         self.finished = threading.Event()
  751.  
  752.     def serve_until_stopped(self):
  753.         while not self.abort:
  754.             rd, wr, ex = select.select([self.socket.fileno()], [], [],
  755.                                        self.timeout)
  756.             if rd:
  757.                 self.handle_request()
  758.         # Notify the main thread that we're about to exit
  759.         self.finished.set()
  760.         # close the listen socket
  761.         self.server_close()
  762.  
  763.  
  764. class SocketHandlerTest(BaseTest):
  765.  
  766.     """Test for SocketHandler objects."""
  767.  
  768.     def setUp(self):
  769.         """Set up a TCP server to receive log messages, and a SocketHandler
  770.         pointing to that server's address and port."""
  771.         BaseTest.setUp(self)
  772.         self.tcpserver = LogRecordSocketReceiver(port=0)
  773.         self.port = self.tcpserver.socket.getsockname()[1]
  774.         self.threads = [
  775.                 threading.Thread(target=self.tcpserver.serve_until_stopped)]
  776.         for thread in self.threads:
  777.             thread.start()
  778.  
  779.         self.sock_hdlr = logging.handlers.SocketHandler('localhost', self.port)
  780.         self.sock_hdlr.setFormatter(self.root_formatter)
  781.         self.root_logger.removeHandler(self.root_logger.handlers[0])
  782.         self.root_logger.addHandler(self.sock_hdlr)
  783.  
  784.     def tearDown(self):
  785.         """Shutdown the TCP server."""
  786.         try:
  787.             self.tcpserver.abort = True
  788.             del self.tcpserver
  789.             self.root_logger.removeHandler(self.sock_hdlr)
  790.             self.sock_hdlr.close()
  791.             for thread in self.threads:
  792.                 thread.join(2.0)
  793.         finally:
  794.             BaseTest.tearDown(self)
  795.  
  796.     def get_output(self):
  797.         """Get the log output as received by the TCP server."""
  798.         # Signal the TCP receiver and wait for it to terminate.
  799.         self.root_logger.critical(LogRecordStreamHandler.TCP_LOG_END)
  800.         self.tcpserver.finished.wait(2.0)
  801.         return self.tcpserver.log_output
  802.  
  803.     def test_output(self):
  804.         # The log message sent to the SocketHandler is properly received.
  805.         logger = logging.getLogger("tcp")
  806.         logger.error("spam")
  807.         logger.debug("eggs")
  808.         self.assertEquals(self.get_output(), "spam\neggs\n")
  809.  
  810.  
  811. class MemoryTest(BaseTest):
  812.  
  813.     """Test memory persistence of logger objects."""
  814.  
  815.     def setUp(self):
  816.         """Create a dict to remember potentially destroyed objects."""
  817.         BaseTest.setUp(self)
  818.         self._survivors = {}
  819.  
  820.     def _watch_for_survival(self, *args):
  821.         """Watch the given objects for survival, by creating weakrefs to
  822.         them."""
  823.         for obj in args:
  824.             key = id(obj), repr(obj)
  825.             self._survivors[key] = weakref.ref(obj)
  826.  
  827.     def _assert_survival(self):
  828.         """Assert that all objects watched for survival have survived."""
  829.         # Trigger cycle breaking.
  830.         gc.collect()
  831.         dead = []
  832.         for (id_, repr_), ref in self._survivors.items():
  833.             if ref() is None:
  834.                 dead.append(repr_)
  835.         if dead:
  836.             self.fail("%d objects should have survived "
  837.                 "but have been destroyed: %s" % (len(dead), ", ".join(dead)))
  838.  
  839.     def test_persistent_loggers(self):
  840.         # Logger objects are persistent and retain their configuration, even
  841.         #  if visible references are destroyed.
  842.         self.root_logger.setLevel(logging.INFO)
  843.         foo = logging.getLogger("foo")
  844.         self._watch_for_survival(foo)
  845.         foo.setLevel(logging.DEBUG)
  846.         self.root_logger.debug(self.next_message())
  847.         foo.debug(self.next_message())
  848.         self.assert_log_lines([
  849.             ('foo', 'DEBUG', '2'),
  850.         ])
  851.         del foo
  852.         # foo has survived.
  853.         self._assert_survival()
  854.         # foo has retained its settings.
  855.         bar = logging.getLogger("foo")
  856.         bar.debug(self.next_message())
  857.         self.assert_log_lines([
  858.             ('foo', 'DEBUG', '2'),
  859.             ('foo', 'DEBUG', '3'),
  860.         ])
  861.  
  862. class EncodingTest(BaseTest):
  863.     def test_encoding_plain_file(self):
  864.         # In Python 2.x, a plain file object is treated as having no encoding.
  865.         log = logging.getLogger("test")
  866.         fn = tempfile.mktemp(".log")
  867.         # the non-ascii data we write to the log.
  868.         data = "foo\x80"
  869.         try:
  870.             handler = logging.FileHandler(fn)
  871.             log.addHandler(handler)
  872.             try:
  873.                 # write non-ascii data to the log.
  874.                 log.warning(data)
  875.             finally:
  876.                 log.removeHandler(handler)
  877.                 handler.close()
  878.             # check we wrote exactly those bytes, ignoring trailing \n etc
  879.             f = open(fn)
  880.             try:
  881.                 self.failUnlessEqual(f.read().rstrip(), data)
  882.             finally:
  883.                 f.close()
  884.         finally:
  885.             if os.path.isfile(fn):
  886.                 os.remove(fn)
  887.  
  888. # Set the locale to the platform-dependent default.  I have no idea
  889. # why the test does this, but in any case we save the current locale
  890. # first and restore it at the end.
  891. @run_with_locale('LC_ALL', '')
  892. def test_main():
  893.     run_unittest(BuiltinLevelsTest, BasicFilterTest,
  894.                     CustomLevelsAndFiltersTest, MemoryHandlerTest,
  895.                     ConfigFileTest, SocketHandlerTest, MemoryTest,
  896.                     EncodingTest)
  897.  
  898. if __name__ == "__main__":
  899.     test_main()
  900.