Merge lp:~jimbaker/pyjuju/standardize-log-testing into lp:pyjuju

[Jim Baker]

This branch standardizes the log testing as seen in hook tests and
test_status and makes it more robust as follows:

 * Removed usage and definition of save_logging, reset_logging, and
   assertInDefaultLog from codebase in favor of the standard usage of
   capture_logging and assertIn, including the use of custom
   formatters as appropriate. It seems like that the use of
   save_logging and related functions was to ensure that any changes
   in formatting or log levels for a log would not interfere with
   other tests. However, capture_logging fully ensures the
   independence of such operations from test to test.

 * Refactored test_status to use our cooperative inheritance
   convention.

 * HookProtocol now uses processEnded to ensure that output streams
   are ready for reading. This was the problem that prompted the
   investigation to begin with: why are some hook tests not able to
   loop properly. This change fixes this problem.

 * Removed unnecessary test timeout override in client-server
   communications tests. It's not clear why a smaller timeout here vs
   in any other place is useful.

[Gustavo Niemeyer (niemeyer)]

This looks like a nice clean up, thanks Jim.

One question:

[1]

8 - yield ServiceStateManagerTestBase.setUp(self)
9 - yield ControlToolTest.setUp(self)
10 - self.save_logging()
11 + yield super(StatusTestBase, self).setUp()
12 + self.log = self.capture_logging()

Have you checked that _all_ of the base classes conform to this protocol, yielding on
every call to setUp? If one does not, we'll have issues.

review: Needs Information

[Jim Baker (jimbaker)]

On Tue, Jun 14, 2011 at 1:44 PM, Gustavo Niemeyer <email address hidden>wrote:

> Review: Needs Information
> This looks like a nice clean up, thanks Jim.
>
> One question:
>
> [1]
>
> 8 - yield ServiceStateManagerTestBase.setUp(self)
> 9 - yield ControlToolTest.setUp(self)
> 10 - self.save_logging()
> 11 + yield super(StatusTestBase, self).setUp()
> 12 + self.log = self.capture_logging()
>
> Have you checked that _all_ of the base classes conform to this protocol,
> yielding on
> every call to setUp? If one does not, we'll have issues.
>

I have rechecked that, and yes, they all conform to the cooperative
inheritance protocol. This was addressed in r120 in trunk for all ancestor
classes here. We may want to scan other test classes to see if there's been
other slippage since then, of course with any possible fixes in a different
branch.

[Gustavo Niemeyer (niemeyer)]

LGTM then, +1!

review: Approve

[Jim Baker (jimbaker)]

Some things to add, especially with respect to our new weekly report:

 * Removing the non-standardized log testing initially created more
   timing issues around test teardown - certain tests would now
   routinely fail. Further investigation revealed that this was
   because of the use of processExit instead of processEnded. However,
   I didn't look into detail as to why the removed log testing code
   was obscuring this problem; perhaps, it was due to the extra
   synchronization around the logging lock or some other aspect seen
   in saving and restoring settings.

 * Ensuring the output was ready before reading actually fixed a
   user-visible bug. In the previous version of the code, it was
   possible that output from hook invocation would potentially be
   lost.

[Gustavo Niemeyer (niemeyer)]

Putting comments in a merge proposal is not enough for Ahmed to note it in the
weekly report. The technical lingo also has to be tamed for it to make sense
for the report. I barely understand what you mean, let alone a user who's
interested in managing formulas.

[Jim Baker (jimbaker)]

Oh sure, I don't expect Ahmed to pick it up from this merge proposal
discussion, or that it is even in a form that is suitable for such a report
for formula writers. However, the bug was initiated in part to do some sort
of reporting back to a mailing list. So if this is of interest, I can shape
the writing of these conclusions into an appropriate form for such a report.
This can also help address the theme that this development phase is, in
part, working on addressing technical debt.

On the other hand, this might be considered too obscure for a general
audience (and not even that interesting, except to a narrow group of
Twisted-loving developers). Ordinarily that would be my thought on a set of
bug fixes like this.

Please tell me what you think works best!

On Tue, Jun 14, 2011 at 3:18 PM, Gustavo Niemeyer <email address hidden>wrote:

> Putting comments in a merge proposal is not enough for Ahmed to note it in
> the
> weekly report. The technical lingo also has to be tamed for it to make
> sense
> for the report. I barely understand what you mean, let alone a user who's
> interested in managing formulas.
> --
>
> https://code.launchpad.net/~jimbaker/ensemble/standardize-log-testing/+merge/64568<https://code.launchpad.net/%7Ejimbaker/ensemble/standardize-log-testing/+merge/64568>
> You are the owner of lp:~jimbaker/ensemble/standardize-log-testing.
>

[Kapil Thangavelu (hazmat)]

This looks good to me, thanks for looking into this, one comment though.

+ yield self.sleep(1)

looks suspicious. does it really need to sleep for a whole second?

review: Approve

[Jim Baker (jimbaker)]

Yikes, that was from my debugging the timing issues. About to be removed!

On Wed, Jun 15, 2011 at 4:26 PM, Kapil Thangavelu <
<email address hidden>> wrote:

> Review: Approve
> This looks good to me, thanks for looking into this, one comment though.
>
> + yield self.sleep(1)
>
> looks suspicious. does it really need to sleep for a whole second?
> --
>
> https://code.launchpad.net/~jimbaker/ensemble/standardize-log-testing/+merge/64568<https://code.launchpad.net/%7Ejimbaker/ensemble/standardize-log-testing/+merge/64568>
> You are the owner of lp:~jimbaker/ensemble/standardize-log-testing.
>

[lp:~jimbaker/pyjuju/standardize-log-testing]

259. By Jim Baker on 2011-06-15

Removed spurious sleep (shouldn't have been part of push)

=== modified file 'ensemble/control/tests/test_status.py'
--- ensemble/control/tests/test_status.py	2011-04-18 17:06:34 +0000
+++ ensemble/control/tests/test_status.py	2011-06-15 22:43:24 +0000
@@ -24,9 +24,8 @@
 
     @inlineCallbacks
     def setUp(self):
-        yield ServiceStateManagerTestBase.setUp(self)
-        yield ControlToolTest.setUp(self)
-        self.save_logging()
+        yield super(StatusTestBase, self).setUp()
+        self.log = self.capture_logging()
 
         config = {
             "ensemble": "environments",
@@ -385,8 +384,9 @@
 
         yield status.collect(
             None, self.provider, self.client, logging.getLogger())
-        self.assertInDefaultLog(
-            "Machine provider information missing: machine 7")
+        self.assertIn(
+            "Machine provider information missing: machine 7",
+            self.log.getvalue())
 
     @inlineCallbacks
     def test_render_yaml(self):

=== modified file 'ensemble/hooks/invoker.py'
--- ensemble/hooks/invoker.py	2011-04-04 15:04:50 +0000
+++ ensemble/hooks/invoker.py	2011-06-15 22:43:24 +0000
@@ -28,7 +28,7 @@
     def errReceived(self, data):
         self._log.error(data)
 
-    def processExited(self, reason):
+    def processEnded(self, reason):
         exit_code = reason.value.exitCode
         if exit_code in (0, None):
             self.deferred.callback(exit_code)

=== modified file 'ensemble/hooks/tests/test_arguments.py'
--- ensemble/hooks/tests/test_arguments.py	2011-06-01 17:43:29 +0000
+++ ensemble/hooks/tests/test_arguments.py	2011-06-15 22:43:24 +0000
@@ -34,9 +34,6 @@
         verify that the socket argument is accepted from a command
         line flag, or the environment or raises an error.
         """
-        self.save_logging()
-        self.reset_logging()
-
         self.setup_environment()
         os.environ.pop("ENSEMBLE_AGENT_SOCKET", None)
 
@@ -57,8 +54,8 @@
         error = self.failUnlessRaises(SystemExit, cli.parse_args)
         self.assertEquals("No ENSEMBLE_AGENT_SOCKET/-s option found",
                           str(error))
-        self.assertInDefaultLog("No ENSEMBLE_AGENT_SOCKET/-s option found",
-                                err)
+        self.assertIn("No ENSEMBLE_AGENT_SOCKET/-s option found",
+                      err.getvalue())
 
     def test_single_keyvalue(self):
         """

=== modified file 'ensemble/hooks/tests/test_cli.py'
--- ensemble/hooks/tests/test_cli.py	2011-06-09 17:19:26 +0000
+++ ensemble/hooks/tests/test_cli.py	2011-06-15 22:43:24 +0000
@@ -234,7 +234,7 @@
         error = self.failUnlessRaises(SystemExit, cli,
                                       "test_unit foobar".split())
         self.assertEquals(error.code, 2)
-        self.assertInDefaultLog("No ENSEMBLE_AGENT_SOCKET", error_log)
+        self.assertIn("No ENSEMBLE_AGENT_SOCKET", error_log.getvalue())
 
     def test_cli_no_client_id(self):
         # don't set up the environment with a socket
@@ -252,13 +252,11 @@
         error = self.failUnlessRaises(SystemExit, cli,
                                       "test_unit foobar".split())
         self.assertEquals(error.code, 2)
-        self.assertInDefaultLog("No ENSEMBLE_CLIENT_ID", error_log)
+        self.assertIn("No ENSEMBLE_CLIENT_ID", error_log.getvalue())
 
     def test_log_level(self):
         self.setup_environment()
         self.change_args(__file__)
-        self.save_logging()
-        self.reset_logging()
 
         cli = GetCli()
         cli.manage_connection = False
@@ -266,9 +264,10 @@
         self.mocker.replay()
 
         # bad log level
+        log = self.capture_logging()
         cli.setup_parser()
         cli.parse_args("--log-level XYZZY test_unit".split())
-        self.assertInDefaultLog("Invalid log level")
+        self.assertIn("Invalid log level", log.getvalue())
         # still get a default
         self.assertEqual(cli.options.log_level, logging.INFO)
 
@@ -283,8 +282,6 @@
     def test_log_format(self):
         self.setup_environment()
         self.change_args(__file__)
-        self.save_logging()
-        self.reset_logging()
 
         cli = NoopCli()
 
@@ -301,14 +298,12 @@
         self.setup_exit(0)
         self.mocker.replay()
         cli("--format missing".split())
-        self.assertInDefaultLog("missing", err)
-        self.assertInDefaultLog("Namespace", out)
+        self.assertIn("missing", err.getvalue())
+        self.assertIn("Namespace", out.getvalue())
 
     def test_render_error(self):
         self.setup_environment()
         self.change_args(__file__)
-        self.save_logging()
-        self.reset_logging()
 
         cli = ErrorCli()
         # bad log level
@@ -318,7 +313,7 @@
         self.mocker.replay()
         cli("")
         # make sure we got a traceback on stderr
-        self.assertInDefaultLog("Checking render error", err)
+        self.assertIn("Checking render error", err.getvalue())
 
     def test_parse_log_level(self):
         self.assertEquals(parse_log_level("INFO"), logging.INFO)

=== modified file 'ensemble/hooks/tests/test_communications.py'
--- ensemble/hooks/tests/test_communications.py	2011-06-04 03:24:31 +0000
+++ ensemble/hooks/tests/test_communications.py	2011-06-15 22:43:24 +0000
@@ -191,9 +191,13 @@
     """
     client_protocol = UnitAgentClient
     server_protocol = UnitAgentServer
-    # short timeout, these are not long running requests when
-    # correct
-    timeout = 1.0
+
+    @defer.inlineCallbacks
+    def setUp(self):
+        yield super(TestCommunications, self).setUp()
+        self.log = self.capture_logging(
+            level=logging.DEBUG,
+            formatter=logging.Formatter("%(levelname)s %(message)s"))
 
     @defer.inlineCallbacks
     def test_relation_get_command(self):
@@ -252,18 +256,14 @@
 
     @defer.inlineCallbacks
     def test_log_command(self):
-        self.save_logging()
         # This is the default calling convention from clients
         yield self.client.log(logging.WARNING, ["This", "is", "a", "WARNING"])
         yield self.client.log(logging.INFO, "This is INFO")
         yield self.client.log(logging.CRITICAL, ["This is CRITICAL"])
 
-        self.assertInDefaultLog("WARNING This is a WARNING",
-                                self.server_factory._agent_io)
-        self.assertInDefaultLog("INFO This is INFO",
-                                self.server_factory._agent_io)
-        self.assertInDefaultLog("CRITICAL This is CRITICAL",
-                                self.server_factory._agent_io)
+        self.assertIn("WARNING This is a WARNING", self.log.getvalue())
+        self.assertIn("INFO This is INFO", self.log.getvalue())
+        self.assertIn("CRITICAL This is CRITICAL", self.log.getvalue())
 
     @defer.inlineCallbacks
     def test_config_get_command(self):
@@ -299,7 +299,6 @@
 
     @defer.inlineCallbacks
     def test_port_commands(self):
-        self.save_logging()
         mock_service_unit_state = MockServiceState().get_unit_state("mock/0")
         yield self.client.open_port("client-id", 80, "tcp")
         self.assertEqual(mock_service_unit_state.ports, set([(80, "tcp")]))
@@ -308,9 +307,9 @@
         self.assertEqual(mock_service_unit_state.ports, set([(53, "udp")]))
         yield self.client.close_port("client-id", 53, "udp")
         self.assertEqual(mock_service_unit_state.ports, set())
-        self.assertInDefaultLog(
+        self.assertIn(
             "DEBUG opened 80/tcp\n"
             "DEBUG opened 53/udp\n"
             "DEBUG closed 80/tcp\n"
             "DEBUG closed 53/udp\n",
-            self.server_factory._agent_io)
+            self.log.getvalue())

=== modified file 'ensemble/hooks/tests/test_invoker.py'
--- ensemble/hooks/tests/test_invoker.py	2011-06-04 03:24:31 +0000
+++ ensemble/hooks/tests/test_invoker.py	2011-06-15 22:43:24 +0000
@@ -8,6 +8,7 @@
 import yaml
 
 from twisted.internet import defer
+from twisted.python.log import PythonLoggingObserver
 
 import ensemble
 from ensemble import errors
@@ -318,6 +319,10 @@
         self.update_invoker_env("mysql/0", "wordpress/0")
         self.socket_path = self.makeFile()
         self.ua = MockUnitAgent(self.client, self.socket_path)
+        self.log = self.capture_logging(
+            formatter=logging.Formatter(
+                "%(name)s:%(levelname)s:: %(message)s"),
+            level=logging.DEBUG)
 
     @defer.inlineCallbacks
     def tearDown(self):
@@ -358,14 +363,10 @@
         self.assertEqual(env["ENSEMBLE_UNIT_NAME"], "mysql/0")
 
     def test_missing_hook(self):
-        self.save_logging()
-
         exe = self.ua.get_invoker("database", "add", "mysql/0", self.relation)
         self.failUnlessRaises(errors.FileNotFound, exe, "hook-missing")
 
     def test_noexec_hook(self):
-        self.save_logging()
-
         exe = self.ua.get_invoker("database", "add", "mysql/0",
                                   self.relation)
         hook = self.get_test_hook("noexec-hook")
@@ -377,29 +378,25 @@
     @defer.inlineCallbacks
     def test_spawn_success(self):
         """Validate hook with success from exit."""
-        self.save_logging()
-        self.reset_logging()
         exe = self.ua.get_invoker("database", "add", "mysql/0", self.relation)
         result = yield exe(self.get_test_hook("success-hook"))
         self.assertEqual(result, 0)
-        self.assertInDefaultLog("WIN")
-        self.assertInDefaultLog("exit code 0")
+        self.assertIn("WIN", self.log.getvalue())
+        self.assertIn("exit code 0", self.log.getvalue())
 
     @defer.inlineCallbacks
     def test_spawn_fail(self):
         """Validate hook with fail from exit."""
-        self.save_logging()
-        self.reset_logging()
         exe = self.ua.get_invoker("database", "add", "mysql/0", self.relation)
         d = exe(self.get_test_hook("fail-hook"))
         result = yield self.assertFailure(d, errors.FormulaInvocationError)
         self.assertEqual(result.exit_code, 1)
         # ERROR indicate the level name, we are checking that the
         # proper level was logged here
-        self.assertInDefaultLog("ERROR")
+        self.assertIn("ERROR", self.log.getvalue())
         # and the message
-        self.assertInDefaultLog("FAIL")
-        self.assertInDefaultLog("exit code 1")
+        self.assertIn("FAIL", self.log.getvalue())
+        self.assertIn("exit code 1", self.log.getvalue())
 
     def test_path_setup(self):
         """Validate that the path allows finding the executable."""
@@ -460,8 +457,6 @@
 
     def test_get_remote_unit_arg(self):
         """Simple test around remote arg parsing."""
-        self.save_logging()
-
         self.change_environment(ENSEMBLE_UNIT_NAME="mysql/0",
                                 ENSEMBLE_CLIENT_ID="client_id",
                                 ENSEMBLE_AGENT_SOCKET=self.socket_path)
@@ -516,8 +511,6 @@
 
     @defer.inlineCallbacks
     def test_logging(self):
-        self.save_logging()
-        self.reset_logging()
         exe = self.ua.get_invoker("database", "add", "mysql/0", self.relation)
 
         # The echo hook will echo out the value
@@ -533,21 +526,19 @@
         result = yield exe(self.get_test_hook("echo-hook"))
         self.assertEqual(result, 0)
 
-        self.assertInDefaultLog(message)
+        self.assertIn(message, self.log.getvalue())
         # The 'error' was sent via ensemble-log
         # to the UA. Our test UA has a fake log stream
         # which we can check now
         output = self.ua.log_file.getvalue()
-        self.assertInDefaultLog("ERROR:: " + error)
-        self.assertInDefaultLog("INFO:: " + default)
+        self.assertIn("ERROR:: " + error, self.log.getvalue())
+        self.assertIn("INFO:: " + default, self.log.getvalue())
 
         assert message not in output, """Log includes unintended messages"""
 
     @defer.inlineCallbacks
     def test_spawn_cli_list_hook_smart(self):
         """Validate the get hook can transmit values to the hook."""
-        self.save_logging()
-        self.reset_logging()
         exe = self.ua.get_invoker("database", "add", "mysql/0",
                                   self.relation,
                                   client_id="client_id")
@@ -568,13 +559,11 @@
                                             "--format=smart"))
 
         self.assertEqual(result, 0)
-        self.assertInDefaultLog("alpha/0\nbeta/0\n")
+        self.assertIn("alpha/0\nbeta/0\n", self.log.getvalue())
 
     @defer.inlineCallbacks
     def test_spawn_cli_list_hook_eval(self):
         """Validate the get hook can transmit values to the hook."""
-        self.save_logging()
-        self.reset_logging()
         exe = self.ua.get_invoker("database", "add", "mysql/0",
                                   self.relation,
                                   client_id="client_id")
@@ -594,13 +583,11 @@
                                             "--format=eval"))
 
         self.assertEqual(result, 0)
-        self.assertInDefaultLog("alpha/0 beta/0")
+        self.assertIn("alpha/0 beta/0", self.log.getvalue())
 
     @defer.inlineCallbacks
     def test_spawn_cli_list_hook_json(self):
         """Validate the get hook can transmit values to the hook."""
-        self.save_logging()
-        self.reset_logging()
         exe = self.ua.get_invoker("database", "add", "mysql/0",
                                   self.relation,
                                   client_id="client_id")
@@ -619,14 +606,14 @@
         result = yield exe(self.create_hook("relation-list", "--format json"))
 
         self.assertEqual(result, 0)
-        self.assertInDefaultLog('["alpha/0", "beta/0"]')
+        self.assertIn('["alpha/0", "beta/0"]', self.log.getvalue())
 
 
 class PortCommandsTest(RelationInvokerTestBase):
 
     def assertLogLines(self, expected):
         """Asserts that the lines of `expected` exist in order in the log."""
-        logged = self.log_stream.getvalue().split("\n")
+        logged = self.log.getvalue().split("\n")
         expected = iter(expected)
         for line in logged:
             expected, peekat = itertools.tee(expected)
@@ -651,9 +638,6 @@
     @defer.inlineCallbacks
     def test_open_and_close_ports(self):
         """Verify that port hook commands run and changes are immediate."""
-        self.save_logging()
-        self.reset_logging()
-
         unit_state = self.mysql_states["unit"]
         self.assertEqual((yield unit_state.get_open_ports()), [])
 
@@ -705,8 +689,6 @@
     @defer.inlineCallbacks
     def test_open_port_args(self):
         """Verify that open-port properly reports arg parse errors."""
-        self.save_logging()
-        self.reset_logging()
         unit_state = self.mysql_states["unit"]
         exe = self.ua.get_invoker("database", "add", "mysql/0", self.relation)
 
@@ -714,31 +696,32 @@
             exe(self.create_hook("open-port", "80/invalid-protocol")),
             errors.FormulaInvocationError)
         self.assertEqual(result.exit_code, 2)
-        self.assertInDefaultLog(
+        self.assertIn(
             "open-port: error: argument PORT[/PROTOCOL]: "
-            "Invalid protocol, must be 'tcp' or 'udp', got 'invalid-protocol'")
+            "Invalid protocol, must be 'tcp' or 'udp', got 'invalid-protocol'",
+            self.log.getvalue())
 
         result = yield self.assertFailure(
             exe(self.create_hook("open-port", "0/tcp")),
             errors.FormulaInvocationError)
         self.assertEqual(result.exit_code, 2)
-        self.assertInDefaultLog(
+        self.assertIn(
             "open-port: error: argument PORT[/PROTOCOL]: "
-            "Invalid port, must be from 1 to 65535, got 0")
+            "Invalid port, must be from 1 to 65535, got 0",
+            self.log.getvalue())
 
         result = yield self.assertFailure(
             exe(self.create_hook("open-port", "80/udp/extra-info")),
             errors.FormulaInvocationError)
         self.assertEqual(result.exit_code, 2)
-        self.assertInDefaultLog(
+        self.assertIn(
             "open-port: error: argument PORT[/PROTOCOL]: "
-            "Invalid format for port/protocol, got '80/udp/extra-info")
+            "Invalid format for port/protocol, got '80/udp/extra-info",
+            self.log.getvalue())
 
     @defer.inlineCallbacks
     def test_close_port_args(self):
         """Verify that close-port properly reports arg parse errors."""
-        self.save_logging()
-        self.reset_logging()
         unit_state = self.mysql_states["unit"]
         exe = self.ua.get_invoker("database", "add", "mysql/0", self.relation)
 
@@ -746,22 +729,25 @@
             exe(self.create_hook("close-port", "80/invalid-protocol")),
             errors.FormulaInvocationError)
         self.assertEqual(result.exit_code, 2)
-        self.assertInDefaultLog(
+        self.assertIn(
             "close-port: error: argument PORT[/PROTOCOL]: "
-            "Invalid protocol, must be 'tcp' or 'udp', got 'invalid-protocol'")
+            "Invalid protocol, must be 'tcp' or 'udp', got 'invalid-protocol'",
+            self.log.getvalue())
 
         result = yield self.assertFailure(
             exe(self.create_hook("close-port", "0/tcp")),
             errors.FormulaInvocationError)
         self.assertEqual(result.exit_code, 2)
-        self.assertInDefaultLog(
+        self.assertIn(
             "close-port: error: argument PORT[/PROTOCOL]: "
-            "Invalid port, must be from 1 to 65535, got 0")
+            "Invalid port, must be from 1 to 65535, got 0",
+            self.log.getvalue())
 
         result = yield self.assertFailure(
             exe(self.create_hook("close-port", "80/udp/extra-info")),
             errors.FormulaInvocationError)
         self.assertEqual(result.exit_code, 2)
-        self.assertInDefaultLog(
+        self.assertIn(
             "close-port: error: argument PORT[/PROTOCOL]: "
-            "Invalid format for port/protocol, got '80/udp/extra-info")
+            "Invalid format for port/protocol, got '80/udp/extra-info",
+            self.log.getvalue())

=== modified file 'ensemble/lib/testing.py'
--- ensemble/lib/testing.py	2011-03-18 21:18:49 +0000
+++ ensemble/lib/testing.py	2011-06-15 22:43:24 +0000
@@ -6,7 +6,6 @@
 from twisted.internet.defer import Deferred, inlineCallbacks, returnValue
 from twisted.internet import reactor
 from twisted.trial.unittest import TestCase as TrialTestCase
-from twisted.python.log import PythonLoggingObserver
 
 from txzookeeper import ZookeeperClient
 
@@ -55,86 +54,6 @@
 
         return log_file
 
-    log_format = "%(name)s:%(levelname)s:: %(message)s"
-
-    def save_logging(self):
-        """
-        Save stdlib's logging settings (which are kept in globals)
-        and restore them after a test run.
-        """
-        logger_dict = logging.getLogger().manager.loggerDict
-        logging._acquireLock()
-        try:
-            self.saved_handlers = logging._handlers.copy()
-            self.saved_handler_list = logging._handlerList[:]
-            self.saved_loggers = logger_dict.copy()
-            self.saved_level_names = logging._levelNames.copy()
-        finally:
-            logging._releaseLock()
-
-        self.root_logger = logging.getLogger("")
-        self.original_logging_level = self.root_logger.getEffectiveLevel()
-
-        self.log_stream = StringIO.StringIO()
-        self.root_logger.setLevel(logging.DEBUG)
-        self.root_hdlr = logging.StreamHandler(self.log_stream)
-        self.root_formatter = logging.Formatter(self.log_format)
-        self.root_hdlr.setFormatter(self.root_formatter)
-        self.root_logger.addHandler(self.root_hdlr)
-        self.log_observer = PythonLoggingObserver()
-        self.log_observer.start()
-
-        @self.addCleanup
-        def restore_logging():
-            self.log_stream.close()
-            self.root_logger.removeHandler(self.root_hdlr)
-            while self.root_logger.handlers:
-                h = self.root_logger.handlers[0]
-                self.root_logger.removeHandler(h)
-                h.close()
-            self.root_logger.setLevel(self.original_logging_level)
-
-            logging._acquireLock()
-            try:
-                logging._levelNames.clear()
-                logging._levelNames.update(self.saved_level_names)
-                logging._handlers.clear()
-                logging._handlers.update(self.saved_handlers)
-                logging._handlerList[:] = self.saved_handler_list
-                loggerDict = logging.getLogger().manager.loggerDict
-                loggerDict.clear()
-                loggerDict.update(self.saved_loggers)
-            finally:
-                logging._releaseLock()
-                self.log_observer.stop()
-
-    def reset_logging(self):
-        """
-        reset all logging to a normalized state.
-        """
-
-        logger_dict = logging.getLogger().manager.loggerDict
-        logging._acquireLock()
-        try:
-            logger_dict.clear()
-            logging._handlers.clear()
-            del logging._handlerList[:]
-            logging.getLogger().manager.loggerDict = {}
-        finally:
-            logging._releaseLock()
-
-    def assertInDefaultLog(self, expected_value, iobuffer=None):
-        """
-        assertInDefaultLog(value, [iobuffer])
-
-        used in conjunction with self.save_logging() this will test
-        for expected values in the default logging stream. An
-        alternative StringIO buffer may be passed as a second value.
-        """
-        stream = iobuffer or self.log_stream
-        content = stream.getvalue()
-        return self.assertIn(expected_value, content)
-
     _missing_attr = object()
 
     def patch(self, object, attr, value):