from contextlib import closing
import datetime
import gzip
+import logging
import os
import shutil
import socket
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)
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.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()
@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
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",
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",
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:
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:
from tornado.web import RequestHandler, Application
import errno
import hashlib
+import logging
import os
import platform
import random
# 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()
# 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()
# 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:
# 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()
# 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:
# 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:
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):
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:
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)
"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)
logger: Union[logging.Logger, basestring_type],
regex: str,
required: bool = True,
+ level: Optional[int] = None,
) -> None:
"""Constructs an ExpectLog context manager.
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)
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
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")