Merge pull request #2799 from tornadoweb/wintest

Improve tests on windows

.gitattributes

@@ -0,0 +1,4 @@
+# Tests of static file handling assume unix-style line endings.
+tornado/test/static/*.txt text eol=lf
+tornado/test/static/dir/*.html text eol=lf
+tornado/test/templates/*.html text eol=lf

appveyor.yml

@@ -50,6 +50,18 @@ environment:
       TOX_ENV: "py37"
       TOX_ARGS: ""
 
+    - PYTHON: "C:\\Python38"
+      PYTHON_VERSION: "3.8.x"
+      PYTHON_ARCH: "32"
+      TOX_ENV: "py38"
+      TOX_ARGS: "tornado.test.websocket_test"
+
+    - PYTHON: "C:\\Python38-x64"
+      PYTHON_VERSION: "3.8.x"
+      PYTHON_ARCH: "64"
+      TOX_ENV: "py38"
+      TOX_ARGS: ""
+
 install:
   # Make sure the right python version is first on the PATH.
   - "SET PATH=%PYTHON%;%PYTHON%\\Scripts;%PATH%"

tornado/platform/asyncio.py

@@ -21,6 +21,7 @@
 
 import concurrent.futures
 import functools
+import sys
 
 from threading import get_ident
 from tornado.gen import convert_yielded
@@ -307,7 +308,15 @@ def to_asyncio_future(tornado_future: asyncio.Future) -> asyncio.Future:
     return convert_yielded(tornado_future)
 
 
-class AnyThreadEventLoopPolicy(asyncio.DefaultEventLoopPolicy):  # type: ignore
+if sys.platform == "win32" and hasattr(asyncio, "WindowsSelectorEventLoopPolicy"):
+    # "Any thread" and "selector" should be orthogonal, but there's not a clean
+    # interface for composing policies so pick the right base.
+    _BasePolicy = asyncio.WindowsSelectorEventLoopPolicy  # type: ignore
+else:
+    _BasePolicy = asyncio.DefaultEventLoopPolicy
+
+
+class AnyThreadEventLoopPolicy(_BasePolicy):  # type: ignore
     """Event loop policy that allows loop creation on any thread.
 
     The default `asyncio` event loop policy only automatically creates

tornado/test/__init__.py

@@ -0,0 +1,8 @@
+import asyncio
+import sys
+
+# Use the selector event loop on windows. Do this in tornado/test/__init__.py
+# instead of runtests.py so it happens no matter how the test is run (such as
+# through editor integrations).
+if sys.platform == "win32" and hasattr(asyncio, "WindowsSelectorEventLoopPolicy"):
+    asyncio.set_event_loop_policy(asyncio.WindowsSelectorEventLoopPolicy())  # type: ignore

tornado/test/httpserver_test.py

@@ -34,6 +34,7 @@
 from contextlib import closing
 import datetime
 import gzip
+import logging
 import os
 import shutil
 import socket
@@ -480,7 +481,7 @@ def test_empty_request(self):
         self.wait()
 
     def test_malformed_first_line_response(self):
-        with ExpectLog(gen_log, ".*Malformed HTTP request line"):
+        with ExpectLog(gen_log, ".*Malformed HTTP request line", level=logging.INFO):
             self.stream.write(b"asdf\r\n\r\n")
             start_line, headers, response = self.io_loop.run_sync(
                 lambda: read_stream_body(self.stream)
@@ -490,15 +491,19 @@ def test_malformed_first_line_response(self):
             self.assertEqual("Bad Request", start_line.reason)
 
     def test_malformed_first_line_log(self):
-        with ExpectLog(gen_log, ".*Malformed HTTP request line"):
+        with ExpectLog(gen_log, ".*Malformed HTTP request line", level=logging.INFO):
             self.stream.write(b"asdf\r\n\r\n")
             # TODO: need an async version of ExpectLog so we don't need
             # hard-coded timeouts here.
             self.io_loop.add_timeout(datetime.timedelta(seconds=0.05), self.stop)
             self.wait()
 
     def test_malformed_headers(self):
-        with ExpectLog(gen_log, ".*Malformed HTTP message.*no colon in header line"):
+        with ExpectLog(
+            gen_log,
+            ".*Malformed HTTP message.*no colon in header line",
+            level=logging.INFO,
+        ):
             self.stream.write(b"GET / HTTP/1.0\r\nasdf\r\n\r\n")
             self.io_loop.add_timeout(datetime.timedelta(seconds=0.05), self.stop)
             self.wait()
@@ -553,7 +558,9 @@ def test_chunked_request_uppercase(self):
 
     @gen_test
     def test_invalid_content_length(self):
-        with ExpectLog(gen_log, ".*Only integer Content-Length is allowed"):
+        with ExpectLog(
+            gen_log, ".*Only integer Content-Length is allowed", level=logging.INFO
+        ):
             self.stream.write(
                 b"""\
 POST /echo HTTP/1.1
@@ -1215,14 +1222,14 @@ def test_small_body(self):
         self.assertEqual(response.body, b"4096")
 
     def test_large_body_buffered(self):
-        with ExpectLog(gen_log, ".*Content-Length too long"):
+        with ExpectLog(gen_log, ".*Content-Length too long", level=logging.INFO):
             response = self.fetch("/buffered", method="PUT", body=b"a" * 10240)
         self.assertEqual(response.code, 400)
 
     @unittest.skipIf(os.name == "nt", "flaky on windows")
     def test_large_body_buffered_chunked(self):
         # This test is flaky on windows for unknown reasons.
-        with ExpectLog(gen_log, ".*chunked body too large"):
+        with ExpectLog(gen_log, ".*chunked body too large", level=logging.INFO):
             response = self.fetch(
                 "/buffered",
                 method="PUT",
@@ -1231,13 +1238,13 @@ def test_large_body_buffered_chunked(self):
         self.assertEqual(response.code, 400)
 
     def test_large_body_streaming(self):
-        with ExpectLog(gen_log, ".*Content-Length too long"):
+        with ExpectLog(gen_log, ".*Content-Length too long", level=logging.INFO):
             response = self.fetch("/streaming", method="PUT", body=b"a" * 10240)
         self.assertEqual(response.code, 400)
 
     @unittest.skipIf(os.name == "nt", "flaky on windows")
     def test_large_body_streaming_chunked(self):
-        with ExpectLog(gen_log, ".*chunked body too large"):
+        with ExpectLog(gen_log, ".*chunked body too large", level=logging.INFO):
             response = self.fetch(
                 "/streaming",
                 method="PUT",
@@ -1270,7 +1277,7 @@ def test_timeout(self):
                 b"PUT /streaming?body_timeout=0.1 HTTP/1.0\r\n"
                 b"Content-Length: 42\r\n\r\n"
             )
-            with ExpectLog(gen_log, "Timeout reading body"):
+            with ExpectLog(gen_log, "Timeout reading body", level=logging.INFO):
                 response = yield stream.read_until_close()
             self.assertEqual(response, b"")
         finally:
@@ -1294,7 +1301,7 @@ def test_body_size_override_reset(self):
             stream.write(
                 b"PUT /streaming HTTP/1.1\r\n" b"Content-Length: 10240\r\n\r\n"
             )
-            with ExpectLog(gen_log, ".*Content-Length too long"):
+            with ExpectLog(gen_log, ".*Content-Length too long", level=logging.INFO):
                 data = yield stream.read_until_close()
             self.assertEqual(data, b"HTTP/1.1 400 Bad Request\r\n\r\n")
         finally:

tornado/test/iostream_test.py

@@ -25,6 +25,7 @@
 from tornado.web import RequestHandler, Application
 import errno
 import hashlib
+import logging
 import os
 import platform
 import random
@@ -366,7 +367,7 @@ def test_read_until_max_bytes(self: typing.Any):
 
             # Not enough space, but we don't know it until all we can do is
             # log a warning and close the connection.
-            with ExpectLog(gen_log, "Unsatisfiable read"):
+            with ExpectLog(gen_log, "Unsatisfiable read", level=logging.INFO):
                 fut = rs.read_until(b"def", max_bytes=5)
                 ws.write(b"123456")
                 yield closed.wait()
@@ -385,7 +386,7 @@ def test_read_until_max_bytes_inline(self: typing.Any):
             # inline.  For consistency with the out-of-line case, we
             # do not raise the error synchronously.
             ws.write(b"123456")
-            with ExpectLog(gen_log, "Unsatisfiable read"):
+            with ExpectLog(gen_log, "Unsatisfiable read", level=logging.INFO):
                 with self.assertRaises(StreamClosedError):
                     yield rs.read_until(b"def", max_bytes=5)
             yield closed.wait()
@@ -403,7 +404,7 @@ def test_read_until_max_bytes_ignores_extra(self: typing.Any):
             # puts us over the limit, we fail the request because it was not
             # found within the limit.
             ws.write(b"abcdef")
-            with ExpectLog(gen_log, "Unsatisfiable read"):
+            with ExpectLog(gen_log, "Unsatisfiable read", level=logging.INFO):
                 rs.read_until(b"def", max_bytes=5)
                 yield closed.wait()
         finally:
@@ -430,7 +431,7 @@ def test_read_until_regex_max_bytes(self: typing.Any):
 
             # Not enough space, but we don't know it until all we can do is
             # log a warning and close the connection.
-            with ExpectLog(gen_log, "Unsatisfiable read"):
+            with ExpectLog(gen_log, "Unsatisfiable read", level=logging.INFO):
                 rs.read_until_regex(b"def", max_bytes=5)
                 ws.write(b"123456")
                 yield closed.wait()
@@ -449,7 +450,7 @@ def test_read_until_regex_max_bytes_inline(self: typing.Any):
             # inline.  For consistency with the out-of-line case, we
             # do not raise the error synchronously.
             ws.write(b"123456")
-            with ExpectLog(gen_log, "Unsatisfiable read"):
+            with ExpectLog(gen_log, "Unsatisfiable read", level=logging.INFO):
                 rs.read_until_regex(b"def", max_bytes=5)
                 yield closed.wait()
         finally:
@@ -466,7 +467,7 @@ def test_read_until_regex_max_bytes_ignores_extra(self):
             # puts us over the limit, we fail the request because it was not
             # found within the limit.
             ws.write(b"abcdef")
-            with ExpectLog(gen_log, "Unsatisfiable read"):
+            with ExpectLog(gen_log, "Unsatisfiable read", level=logging.INFO):
                 rs.read_until_regex(b"def", max_bytes=5)
                 yield closed.wait()
         finally:

tornado/test/netutil_test.py

@@ -163,6 +163,7 @@ def test_import(self):
 # name with spaces used in this test.
 @skipIfNoNetwork
 @unittest.skipIf(pycares is None, "pycares module not present")
+@unittest.skipIf(sys.platform == "win32", "pycares doesn't return loopback on windows")
 class CaresResolverTest(AsyncTestCase, _ResolverTestMixin):
     def setUp(self):
         super(CaresResolverTest, self).setUp()
@@ -181,6 +182,7 @@ def setUp(self):
 @unittest.skipIf(
     getattr(twisted, "__version__", "0.0") < "12.1", "old version of twisted"
 )
+@unittest.skipIf(sys.platform == "win32", "twisted resolver hangs on windows")
 class TwistedResolverTest(AsyncTestCase, _ResolverTestMixin):
     def setUp(self):
         super(TwistedResolverTest, self).setUp()

tornado/test/simple_httpclient_test.py

@@ -316,7 +316,9 @@ def test_multiple_content_length_accepted(self: typing.Any):
         response = self.fetch("/content_length?value=2,%202,2")
         self.assertEqual(response.body, b"ok")
 
-        with ExpectLog(gen_log, ".*Multiple unequal Content-Lengths"):
+        with ExpectLog(
+            gen_log, ".*Multiple unequal Content-Lengths", level=logging.INFO
+        ):
             with self.assertRaises(HTTPStreamClosedError):
                 self.fetch("/content_length?value=2,4", raise_error=True)
             with self.assertRaises(HTTPStreamClosedError):
@@ -657,7 +659,9 @@ def test_204_no_content(self):
 
     def test_204_invalid_content_length(self):
         # 204 status with non-zero content length is malformed
-        with ExpectLog(gen_log, ".*Response with code 204 should not have body"):
+        with ExpectLog(
+            gen_log, ".*Response with code 204 should not have body", level=logging.INFO
+        ):
             with self.assertRaises(HTTPStreamClosedError):
                 self.fetch("/?error=1", raise_error=True)
                 if not self.http1:
@@ -768,7 +772,9 @@ def test_small_body(self):
 
     def test_large_body(self):
         with ExpectLog(
-            gen_log, "Malformed HTTP message from None: Content-Length too long"
+            gen_log,
+            "Malformed HTTP message from None: Content-Length too long",
+            level=logging.INFO,
         ):
             with self.assertRaises(HTTPStreamClosedError):
                 self.fetch("/large", raise_error=True)
@@ -815,6 +821,7 @@ def test_chunked_with_content_length(self):
                 "Malformed HTTP message from None: Response "
                 "with both Transfer-Encoding and Content-Length"
             ),
+            level=logging.INFO,
         ):
             with self.assertRaises(HTTPStreamClosedError):
                 self.fetch("/chunkwithcl", raise_error=True)

tornado/test/twisted_test.py

@@ -51,7 +51,10 @@
 
 def save_signal_handlers():
     saved = {}
-    for sig in [signal.SIGINT, signal.SIGTERM, signal.SIGCHLD]:
+    signals = [signal.SIGINT, signal.SIGTERM]
+    if hasattr(signal, "SIGCHLD"):
+        signals.append(signal.SIGCHLD)
+    for sig in signals:
         saved[sig] = signal.getsignal(sig)
     if "twisted" in repr(saved):
         # This indicates we're not cleaning up after ourselves properly.

tornado/testing.py

@@ -657,6 +657,7 @@ def __init__(
         logger: Union[logging.Logger, basestring_type],
         regex: str,
         required: bool = True,
+        level: Optional[int] = None,
     ) -> None:
         """Constructs an ExpectLog context manager.
 
@@ -666,6 +667,15 @@ def __init__(
             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.
+
+        .. versionchanged:: 6.1
+           Added the ``level`` parameter.
         """
         if isinstance(logger, basestring_type):
             logger = logging.getLogger(logger)
@@ -674,17 +684,28 @@ def __init__(
         self.required = required
         self.matched = False
         self.logged_stack = False
+        self.level = level
+        self.orig_level = None  # type: Optional[int]
 
     def filter(self, record: logging.LogRecord) -> bool:
         if record.exc_info:
             self.logged_stack = True
         message = record.getMessage()
         if self.regex.match(message):
+            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
             return False
         return True
 
     def __enter__(self) -> "ExpectLog":
+        if self.level is not None and self.level < self.logger.getEffectiveLevel():
+            self.orig_level = self.logger.level
+            self.logger.setLevel(self.level)
         self.logger.addFilter(self)
         return self
 
@@ -694,6 +715,8 @@ def __exit__(
         value: Optional[BaseException],
         tb: Optional[TracebackType],
     ) -> None:
+        if self.orig_level is not None:
+            self.logger.setLevel(self.orig_level)
         self.logger.removeFilter(self)
         if not typ and self.required and not self.matched:
             raise Exception("did not get expected log message")