import logging import os import uuid from importlib import reload from io import StringIO from unittest.mock import Mock import pytest import sanic from sanic import Sanic from sanic.log import LOGGING_CONFIG_DEFAULTS, logger from sanic.response import text from sanic.testing import SanicTestClient logging_format = """module: %(module)s; \ function: %(funcName)s(); \ message: %(message)s""" def reset_logging(): logging.shutdown() reload(logging) def test_log(app): log_stream = StringIO() for handler in logging.root.handlers[:]: logging.root.removeHandler(handler) logging.basicConfig( format=logging_format, level=logging.DEBUG, stream=log_stream ) log = logging.getLogger() rand_string = str(uuid.uuid4()) @app.route("/") def handler(request): log.info(rand_string) return text("hello") request, response = app.test_client.get("/") log_text = log_stream.getvalue() assert rand_string in log_text def test_logging_defaults(): # reset_logging() app = Sanic("test_logging") for fmt in [h.formatter for h in logging.getLogger("sanic.root").handlers]: assert ( fmt._fmt == LOGGING_CONFIG_DEFAULTS["formatters"]["generic"]["format"] ) for fmt in [ h.formatter for h in logging.getLogger("sanic.error").handlers ]: assert ( fmt._fmt == LOGGING_CONFIG_DEFAULTS["formatters"]["generic"]["format"] ) for fmt in [ h.formatter for h in logging.getLogger("sanic.access").handlers ]: assert ( fmt._fmt == LOGGING_CONFIG_DEFAULTS["formatters"]["access"]["format"] ) def test_logging_pass_customer_logconfig(): # reset_logging() modified_config = LOGGING_CONFIG_DEFAULTS modified_config["formatters"]["generic"][ "format" ] = "%(asctime)s - (%(name)s)[%(levelname)s]: %(message)s" modified_config["formatters"]["access"][ "format" ] = "%(asctime)s - (%(name)s)[%(levelname)s]: %(message)s" app = Sanic("test_logging", log_config=modified_config) for fmt in [h.formatter for h in logging.getLogger("sanic.root").handlers]: assert fmt._fmt == modified_config["formatters"]["generic"]["format"] for fmt in [ h.formatter for h in logging.getLogger("sanic.error").handlers ]: assert fmt._fmt == modified_config["formatters"]["generic"]["format"] for fmt in [ h.formatter for h in logging.getLogger("sanic.access").handlers ]: assert fmt._fmt == modified_config["formatters"]["access"]["format"] @pytest.mark.parametrize("debug", (True, False)) def test_log_connection_lost(app, debug, monkeypatch): """Should not log Connection lost exception on non debug""" stream = StringIO() root = logging.getLogger("sanic.root") root.addHandler(logging.StreamHandler(stream)) monkeypatch.setattr(sanic.server, "logger", root) @app.route("/conn_lost") async def conn_lost(request): response = text("Ok") response.output = Mock(side_effect=RuntimeError) return response with pytest.raises(ValueError): # catch ValueError: Exception during request app.test_client.get("/conn_lost", debug=debug) log = stream.getvalue() if debug: assert "Connection lost before response written @" in log else: assert "Connection lost before response written @" not in log def test_logger(caplog): rand_string = str(uuid.uuid4()) app = Sanic(name=__name__) @app.get("/") def log_info(request): logger.info(rand_string) return text("hello") with caplog.at_level(logging.INFO): request, response = app.test_client.get("/") port = request.server_port # Note: testing with random port doesn't show the banner because it doesn't # define host and port. This test supports both modes. if caplog.record_tuples[0] == ( "sanic.root", logging.INFO, f"Goin' Fast @ http://127.0.0.1:{port}", ): caplog.record_tuples.pop(0) assert caplog.record_tuples[0] == ( "sanic.root", logging.INFO, f"http://127.0.0.1:{port}/", ) assert caplog.record_tuples[1] == ("sanic.root", logging.INFO, rand_string) assert caplog.record_tuples[-1] == ( "sanic.root", logging.INFO, "Server Stopped", ) def test_logger_static_and_secure(caplog): # Same as test_logger, except for more coverage: # - test_client initialised separately for static port # - using ssl rand_string = str(uuid.uuid4()) app = Sanic(name=__name__) @app.get("/") def log_info(request): logger.info(rand_string) return text("hello") current_dir = os.path.dirname(os.path.realpath(__file__)) ssl_cert = os.path.join(current_dir, "certs/selfsigned.cert") ssl_key = os.path.join(current_dir, "certs/selfsigned.key") ssl_dict = {"cert": ssl_cert, "key": ssl_key} test_client = SanicTestClient(app, port=42101) with caplog.at_level(logging.INFO): request, response = test_client.get( f"https://127.0.0.1:{test_client.port}/", server_kwargs=dict(ssl=ssl_dict), ) port = test_client.port assert caplog.record_tuples[0] == ( "sanic.root", logging.INFO, f"Goin' Fast @ https://127.0.0.1:{port}", ) assert caplog.record_tuples[1] == ( "sanic.root", logging.INFO, f"https://127.0.0.1:{port}/", ) assert caplog.record_tuples[2] == ("sanic.root", logging.INFO, rand_string) assert caplog.record_tuples[-1] == ( "sanic.root", logging.INFO, "Server Stopped", ) def test_logging_modified_root_logger_config(): # reset_logging() modified_config = LOGGING_CONFIG_DEFAULTS modified_config["loggers"]["sanic.root"]["level"] = "DEBUG" app = Sanic("test_logging", log_config=modified_config) assert logging.getLogger("sanic.root").getEffectiveLevel() == logging.DEBUG