From: Ben Darnell Date: Sun, 27 Nov 2022 02:50:04 +0000 (-0500) Subject: testing: Deprecate environment-dependent behavior in ExpectLog X-Git-Tag: v6.3.0b1~22^2~1 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=fb22de0d3eae58cd8ff2b439299440445b1d6e9b;p=thirdparty%2Ftornado.git testing: Deprecate environment-dependent behavior in ExpectLog ExpectLog is sensitive to the difference between tornado.testing.main (which sets the logging level to info) and most other test runners, which do not. In the future ExpectLog will match WARNING and above by default; matching lower levels without using the ``level`` argument is deprecated. Fix one test in httpserver_test.py that is affected by this. --- diff --git a/tornado/test/httpserver_test.py b/tornado/test/httpserver_test.py index 146ed781c..cea31d2e9 100644 --- a/tornado/test/httpserver_test.py +++ b/tornado/test/httpserver_test.py @@ -754,7 +754,7 @@ class UnixSocketTest(AsyncTestCase): def test_unix_socket_bad_request(self): # Unix sockets don't have remote addresses so they just return an # empty string. - with ExpectLog(gen_log, "Malformed HTTP message from"): + with ExpectLog(gen_log, "Malformed HTTP message from", level=logging.INFO): self.stream.write(b"garbage\r\n\r\n") response = yield self.stream.read_until_close() self.assertEqual(response, b"HTTP/1.1 400 Bad Request\r\n\r\n") diff --git a/tornado/test/websocket_test.py b/tornado/test/websocket_test.py index 53d5cde2c..8ce3d512f 100644 --- a/tornado/test/websocket_test.py +++ b/tornado/test/websocket_test.py @@ -388,7 +388,7 @@ class WebSocketTest(WebSocketBaseTestCase): sock, port = bind_unused_port() sock.close() with self.assertRaises(IOError): - with ExpectLog(gen_log, ".*"): + with ExpectLog(gen_log, ".*", required=False): yield websocket_connect( "ws://127.0.0.1:%d/" % port, connect_timeout=3600 ) diff --git a/tornado/testing.py b/tornado/testing.py index fcad60c17..c786a2e5c 100644 --- a/tornado/testing.py +++ b/tornado/testing.py @@ -724,28 +724,37 @@ class ExpectLog(logging.Filter): ) -> None: """Constructs an ExpectLog context manager. - :param logger: Logger object (or name of logger) to watch. Pass - an empty string to watch the root logger. - :param regex: Regular expression to match. Any log entries on - the specified logger that match this regex will be suppressed. - :param required: If true, an exception will be raised if the end of - the ``with`` statement is reached without matching any log entries. + :param logger: Logger object (or name of logger) to watch. Pass an + empty string to watch the root logger. + :param regex: Regular expression to match. Any log entries on the + specified logger that match this regex will be suppressed. + :param required: If true, an exception will be raised if the end of the + ``with`` statement is reached without matching any log entries. :param level: A constant from the ``logging`` module indicating the expected log level. If this parameter is provided, only log messages at this level will be considered to match. Additionally, the - supplied ``logger`` will have its level adjusted if necessary - (for the duration of the ``ExpectLog`` to enable the expected - message. + supplied ``logger`` will have its level adjusted if necessary (for + the duration of the ``ExpectLog`` to enable the expected message. .. versionchanged:: 6.1 Added the ``level`` parameter. + + .. deprecated:: 6.3 + In Tornado 7.0, only ``WARNING`` and higher logging levels will be + matched by default. To match ``INFO`` and lower levels, the ``level`` + argument must be used. This is changing to minimize differences + between ``tornado.testing.main`` (which enables ``INFO`` logs by + default) and most other test runners (including those in IDEs) + which have ``INFO`` logs disabled by default. """ if isinstance(logger, basestring_type): logger = logging.getLogger(logger) self.logger = logger self.regex = re.compile(regex) self.required = required - self.matched = False + # matched and deprecated_level_matched are a counter for the respective event. + self.matched = 0 + self.deprecated_level_matched = 0 self.logged_stack = False self.level = level self.orig_level = None # type: Optional[int] @@ -755,13 +764,20 @@ class ExpectLog(logging.Filter): self.logged_stack = True message = record.getMessage() if self.regex.match(message): + if self.level is None and record.levelno < logging.WARNING: + # We're inside the logging machinery here so generating a DeprecationWarning + # here won't be reported cleanly (if warnings-as-errors is enabled, the error + # just gets swallowed by the logging module), and even if it were it would + # have the wrong stack trace. Just remember this fact and report it in + # __exit__ instead. + self.deprecated_level_matched += 1 if self.level is not None and record.levelno != self.level: app_log.warning( "Got expected log message %r at unexpected level (%s vs %s)" % (message, logging.getLevelName(self.level), record.levelname) ) return True - self.matched = True + self.matched += 1 return False return True @@ -783,6 +799,15 @@ class ExpectLog(logging.Filter): self.logger.removeFilter(self) if not typ and self.required and not self.matched: raise Exception("did not get expected log message") + if ( + not typ + and self.required + and (self.deprecated_level_matched >= self.matched) + ): + warnings.warn( + "ExpectLog matched at INFO or below without level argument", + DeprecationWarning, + ) # From https://nedbatchelder.com/blog/201508/using_context_managers_in_test_setup.html