From 174703ef2f2f35e69eff8dc10be146a68d2c2ccc Mon Sep 17 00:00:00 2001 From: asriniva <69502+asriniva@users.noreply.github.com> Date: Fri, 15 Jan 2021 13:48:27 -0800 Subject: [PATCH 1/8] Add backwards-compatible logging for GCF Python 3.7 --- src/functions_framework/__init__.py | 24 ++++++++++ tests/test_functions.py | 33 +++++++++++++ .../http_check_severity/main.py | 47 +++++++++++++++++++ tox.ini | 1 + 4 files changed, 105 insertions(+) create mode 100644 tests/test_functions/http_check_severity/main.py diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index 356f7a03..6b696f05 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -65,6 +65,17 @@ def __init__( self.data = data +class _LoggingHandler(object): + """Logging replacement for stdout and stderr in GCF Python 3.7.""" + + def __init__(self, level): + self.level = level + + def write(self, out): + if out.rstrip() != "": + self.level(out.rstrip()) + + def _http_view_func_wrapper(function, request): def view_func(path): return function(request._get_current_object()) @@ -221,6 +232,19 @@ def handle_none(rv): app.make_response = handle_none + # Handle log severity backwards compatibility + import logging # isort:skip + from google.cloud.logging_v2.handlers.container_engine import ( # isort:skip + ContainerEngineHandler, + ) + + handler = ContainerEngineHandler() + cloud_logger = logging.getLogger() + cloud_logger.setLevel(logging.DEBUG) + cloud_logger.addHandler(handler) + sys.stdout = _LoggingHandler(logging.info) + sys.stderr = _LoggingHandler(logging.warning) + # Extract the target function from the source file if not hasattr(source_module, target): raise MissingTargetException( diff --git a/tests/test_functions.py b/tests/test_functions.py index 2f0ca05b..cf400650 100644 --- a/tests/test_functions.py +++ b/tests/test_functions.py @@ -495,6 +495,39 @@ def test_legacy_function_check_env(monkeypatch): assert resp.data.decode("utf-8") == target +def test_legacy_function_log_severity(monkeypatch, capsys): + source = TEST_FUNCTIONS_DIR / "http_check_severity" / "main.py" + target = "function" + + monkeypatch.setenv("ENTRY_POINT", target) + + client = create_app(target, source).test_client() + resp = client.post("/", json={"mode": "stdout"}) + captured = capsys.readouterr().err + assert resp.status_code == 200 + assert '"severity": "INFO"' in captured + + resp = client.post("/", json={"mode": "stderr"}) + captured = capsys.readouterr().err + assert resp.status_code == 200 + assert '"severity": "WARNING"' in captured + + resp = client.post("/", json={"mode": "loginfo"}) + captured = capsys.readouterr().err + assert resp.status_code == 200 + assert '"severity": "INFO"' in captured + + resp = client.post("/", json={"mode": "logwarn"}) + captured = capsys.readouterr().err + assert resp.status_code == 200 + assert '"severity": "WARNING"' in captured + + resp = client.post("/", json={"mode": "logerr"}) + captured = capsys.readouterr().err + assert resp.status_code == 200 + assert '"severity": "ERROR"' in captured + + def test_legacy_function_returns_none(monkeypatch): source = TEST_FUNCTIONS_DIR / "returns_none" / "main.py" target = "function" diff --git a/tests/test_functions/http_check_severity/main.py b/tests/test_functions/http_check_severity/main.py new file mode 100644 index 00000000..740b716e --- /dev/null +++ b/tests/test_functions/http_check_severity/main.py @@ -0,0 +1,47 @@ +# Copyright 2020 Google LLC +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. + +"""Function used in Worker tests of legacy GCF Python 3.7 logging.""" +import logging +import os +import sys + +X_GOOGLE_FUNCTION_NAME = "gcf-function" +X_GOOGLE_ENTRY_POINT = "function" +HOME = "/tmp" + + +def function(request): + """Test function which logs to the appropriate output. + + Args: + request: The HTTP request which triggered this function. Must contain name + of the requested output in the 'mode' field in JSON document + in request body. + + Returns: + Value of the mode. + """ + name = request.get_json().get("mode") + if name == "stdout": + print("log") + elif name == "stderr": + print("log", file=sys.stderr) + elif name == "loginfo": + logging.info("log") + elif name == "logwarn": + logging.warning("log") + elif name == "logerr": + logging.error("log") + return name diff --git a/tox.ini b/tox.ini index e4a251bd..6985b34a 100644 --- a/tox.ini +++ b/tox.ini @@ -5,6 +5,7 @@ envlist = py{35,36,37,38,39}-{ubuntu-latest,macos-latest,windows-latest},lint usedevelop = true deps = docker + google-cloud-logging pytest-cov pytest-integration pretend From 33762d12b33d151534f2db76156f136533106499 Mon Sep 17 00:00:00 2001 From: asriniva <69502+asriniva@users.noreply.github.com> Date: Fri, 22 Jan 2021 13:03:56 -0800 Subject: [PATCH 2/8] Reformatted --- src/functions_framework/__init__.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index 6b696f05..5db5c4e3 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -233,8 +233,8 @@ def handle_none(rv): app.make_response = handle_none # Handle log severity backwards compatibility - import logging # isort:skip - from google.cloud.logging_v2.handlers.container_engine import ( # isort:skip + import logging # isort:skip + from google.cloud.logging_v2.handlers.container_engine import ( # isort:skip ContainerEngineHandler, ) From a24ca311c54da8da971bce199af748fe117bb9a1 Mon Sep 17 00:00:00 2001 From: Arjun Srinivasan <69502+asriniva@users.noreply.github.com> Date: Fri, 22 Jan 2021 13:23:55 -0800 Subject: [PATCH 3/8] Update src/functions_framework/__init__.py Co-authored-by: Dustin Ingram --- src/functions_framework/__init__.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index 5db5c4e3..03794fea 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -72,7 +72,7 @@ def __init__(self, level): self.level = level def write(self, out): - if out.rstrip() != "": + if out.rstrip(): self.level(out.rstrip()) From 9c6d0be4bcca61f4344e8025e479b885041303e4 Mon Sep 17 00:00:00 2001 From: asriniva <69502+asriniva@users.noreply.github.com> Date: Fri, 22 Jan 2021 14:25:47 -0800 Subject: [PATCH 4/8] Restructure logging to better fit legacy behavior --- conftest.py | 18 +++++++++ src/functions_framework/__init__.py | 26 ++++++------ tests/test_functions.py | 40 ++++++++----------- .../http_check_severity/main.py | 2 + tox.ini | 1 - 5 files changed, 50 insertions(+), 37 deletions(-) diff --git a/conftest.py b/conftest.py index b8d44d43..b29a3ebb 100644 --- a/conftest.py +++ b/conftest.py @@ -12,7 +12,11 @@ # See the License for the specific language governing permissions and # limitations under the License. +import logging import os +import sys + +from importlib import reload import pytest @@ -26,3 +30,17 @@ def isolate_environment(): finally: os.environ.clear() os.environ.update(_environ) + + +@pytest.fixture(scope="function", autouse=True) +def isolate_logging(): + "Ensure any changes to logging are isolated to individual tests" "" + _stdout = sys.stdout + _stderr = sys.stderr + try: + yield + finally: + sys.stdout = _stdout + sys.stderr = _stderr + logging.shutdown() + reload(logging) diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index 03794fea..fac48d32 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -68,12 +68,16 @@ def __init__( class _LoggingHandler(object): """Logging replacement for stdout and stderr in GCF Python 3.7.""" - def __init__(self, level): + def __init__(self, level, stderr): self.level = level + self.stderr = stderr def write(self, out): - if out.rstrip(): - self.level(out.rstrip()) + self._log_with_severity(out.rstrip("\n")) + + def _log_with_severity(self, out): + payload = dict(severity=self.level, message=out) + print(json.dumps(payload), file=self.stderr) def _http_view_func_wrapper(function, request): @@ -234,16 +238,14 @@ def handle_none(rv): # Handle log severity backwards compatibility import logging # isort:skip - from google.cloud.logging_v2.handlers.container_engine import ( # isort:skip - ContainerEngineHandler, - ) - handler = ContainerEngineHandler() - cloud_logger = logging.getLogger() - cloud_logger.setLevel(logging.DEBUG) - cloud_logger.addHandler(handler) - sys.stdout = _LoggingHandler(logging.info) - sys.stderr = _LoggingHandler(logging.warning) + logging.info = _LoggingHandler("INFO", sys.stderr)._log_with_severity + logging.warn = _LoggingHandler("ERROR", sys.stderr)._log_with_severity + logging.warning = _LoggingHandler("ERROR", sys.stderr)._log_with_severity + logging.error = _LoggingHandler("ERROR", sys.stderr)._log_with_severity + logging.critical = _LoggingHandler("ERROR", sys.stderr)._log_with_severity + sys.stdout = _LoggingHandler("INFO", sys.stderr) + sys.stderr = _LoggingHandler("ERROR", sys.stderr) # Extract the target function from the source file if not hasattr(source_module, target): diff --git a/tests/test_functions.py b/tests/test_functions.py index cf400650..5f746931 100644 --- a/tests/test_functions.py +++ b/tests/test_functions.py @@ -16,6 +16,7 @@ import os import pathlib import re +import sys import time import pretend @@ -495,37 +496,28 @@ def test_legacy_function_check_env(monkeypatch): assert resp.data.decode("utf-8") == target -def test_legacy_function_log_severity(monkeypatch, capsys): +@pytest.mark.parametrize( + "mode, expected", + [ + ("loginfo", '"severity": "INFO"'), + ("logwarn", '"severity": "ERROR"'), + ("logerr", '"severity": "ERROR"'), + ("logcrit", '"severity": "ERROR"'), + ("stdout", '"severity": "INFO"'), + ("stderr", '"severity": "ERROR"'), + ], +) +def test_legacy_function_log_severity(monkeypatch, capfd, mode, expected): source = TEST_FUNCTIONS_DIR / "http_check_severity" / "main.py" target = "function" monkeypatch.setenv("ENTRY_POINT", target) client = create_app(target, source).test_client() - resp = client.post("/", json={"mode": "stdout"}) - captured = capsys.readouterr().err - assert resp.status_code == 200 - assert '"severity": "INFO"' in captured - - resp = client.post("/", json={"mode": "stderr"}) - captured = capsys.readouterr().err - assert resp.status_code == 200 - assert '"severity": "WARNING"' in captured - - resp = client.post("/", json={"mode": "loginfo"}) - captured = capsys.readouterr().err - assert resp.status_code == 200 - assert '"severity": "INFO"' in captured - - resp = client.post("/", json={"mode": "logwarn"}) - captured = capsys.readouterr().err - assert resp.status_code == 200 - assert '"severity": "WARNING"' in captured - - resp = client.post("/", json={"mode": "logerr"}) - captured = capsys.readouterr().err + resp = client.post("/", json={"mode": mode}) + captured = capfd.readouterr().err assert resp.status_code == 200 - assert '"severity": "ERROR"' in captured + assert expected in captured def test_legacy_function_returns_none(monkeypatch): diff --git a/tests/test_functions/http_check_severity/main.py b/tests/test_functions/http_check_severity/main.py index 740b716e..be586d8d 100644 --- a/tests/test_functions/http_check_severity/main.py +++ b/tests/test_functions/http_check_severity/main.py @@ -44,4 +44,6 @@ def function(request): logging.warning("log") elif name == "logerr": logging.error("log") + elif name == "logcrit": + logging.critical("log") return name diff --git a/tox.ini b/tox.ini index 6985b34a..e4a251bd 100644 --- a/tox.ini +++ b/tox.ini @@ -5,7 +5,6 @@ envlist = py{35,36,37,38,39}-{ubuntu-latest,macos-latest,windows-latest},lint usedevelop = true deps = docker - google-cloud-logging pytest-cov pytest-integration pretend From 21e09f4e65ad5a0b49d711f13dff043851a7a232 Mon Sep 17 00:00:00 2001 From: asriniva <69502+asriniva@users.noreply.github.com> Date: Mon, 25 Jan 2021 16:19:56 -0800 Subject: [PATCH 5/8] Modify write behavior to account for newlines --- src/functions_framework/__init__.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index fac48d32..47d23ff0 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -73,11 +73,11 @@ def __init__(self, level, stderr): self.stderr = stderr def write(self, out): - self._log_with_severity(out.rstrip("\n")) + self._log_with_severity(out) def _log_with_severity(self, out): payload = dict(severity=self.level, message=out) - print(json.dumps(payload), file=self.stderr) + self.stderr.write(json.dumps(payload)) def _http_view_func_wrapper(function, request): From a902a14add079044405db38f8cc9d5c32c07936f Mon Sep 17 00:00:00 2001 From: asriniva <69502+asriniva@users.noreply.github.com> Date: Mon, 15 Feb 2021 23:56:21 -0800 Subject: [PATCH 6/8] Update LogHandler to use io.TextIOWrapper --- conftest.py | 6 ++---- src/functions_framework/__init__.py | 26 +++++++++++++++----------- 2 files changed, 17 insertions(+), 15 deletions(-) diff --git a/conftest.py b/conftest.py index b29a3ebb..21572fda 100644 --- a/conftest.py +++ b/conftest.py @@ -35,12 +35,10 @@ def isolate_environment(): @pytest.fixture(scope="function", autouse=True) def isolate_logging(): "Ensure any changes to logging are isolated to individual tests" "" - _stdout = sys.stdout - _stderr = sys.stderr try: yield finally: - sys.stdout = _stdout - sys.stderr = _stderr + sys.stdout = sys.__stdout__ + sys.stderr = sys.__stderr__ logging.shutdown() reload(logging) diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index 47d23ff0..656c7077 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -14,6 +14,7 @@ import functools import importlib.util +import io import json import os.path import pathlib @@ -65,19 +66,22 @@ def __init__( self.data = data -class _LoggingHandler(object): +class _LoggingHandler(io.TextIOWrapper): """Logging replacement for stdout and stderr in GCF Python 3.7.""" - def __init__(self, level, stderr): + def __init__(self, level, stderr=sys.stderr): + io.TextIOWrapper.__init__(self, io.StringIO(), encoding=stderr.encoding) self.level = level self.stderr = stderr def write(self, out): - self._log_with_severity(out) - - def _log_with_severity(self, out): - payload = dict(severity=self.level, message=out) + payload = dict(severity=self.level, message=out.rstrip("\n")) self.stderr.write(json.dumps(payload)) + self.stderr.write("\n") + return len(out.rstrip("\n")) + + def flush(self): + pass def _http_view_func_wrapper(function, request): @@ -239,11 +243,11 @@ def handle_none(rv): # Handle log severity backwards compatibility import logging # isort:skip - logging.info = _LoggingHandler("INFO", sys.stderr)._log_with_severity - logging.warn = _LoggingHandler("ERROR", sys.stderr)._log_with_severity - logging.warning = _LoggingHandler("ERROR", sys.stderr)._log_with_severity - logging.error = _LoggingHandler("ERROR", sys.stderr)._log_with_severity - logging.critical = _LoggingHandler("ERROR", sys.stderr)._log_with_severity + logging.info = _LoggingHandler("INFO", sys.stderr).write + logging.warn = _LoggingHandler("ERROR", sys.stderr).write + logging.warning = _LoggingHandler("ERROR", sys.stderr).write + logging.error = _LoggingHandler("ERROR", sys.stderr).write + logging.critical = _LoggingHandler("ERROR", sys.stderr).write sys.stdout = _LoggingHandler("INFO", sys.stderr) sys.stderr = _LoggingHandler("ERROR", sys.stderr) From c1e5d9219af9d7797dc13ac3f3046f571c594ad2 Mon Sep 17 00:00:00 2001 From: asriniva <69502+asriniva@users.noreply.github.com> Date: Wed, 17 Feb 2021 01:02:42 -0800 Subject: [PATCH 7/8] Simplify write method --- src/functions_framework/__init__.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index 656c7077..3786e27c 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -76,9 +76,7 @@ def __init__(self, level, stderr=sys.stderr): def write(self, out): payload = dict(severity=self.level, message=out.rstrip("\n")) - self.stderr.write(json.dumps(payload)) - self.stderr.write("\n") - return len(out.rstrip("\n")) + return self.stderr.write(json.dumps(payload) + "\n") def flush(self): pass From 4417992ffd6592366cc9e3f4ee198dc7a7d00e7a Mon Sep 17 00:00:00 2001 From: Arjun Srinivasan <69502+asriniva@users.noreply.github.com> Date: Wed, 17 Feb 2021 09:47:55 -0800 Subject: [PATCH 8/8] Update src/functions_framework/__init__.py Co-authored-by: Dustin Ingram --- src/functions_framework/__init__.py | 3 --- 1 file changed, 3 deletions(-) diff --git a/src/functions_framework/__init__.py b/src/functions_framework/__init__.py index 3786e27c..1e87fdb4 100644 --- a/src/functions_framework/__init__.py +++ b/src/functions_framework/__init__.py @@ -78,9 +78,6 @@ def write(self, out): payload = dict(severity=self.level, message=out.rstrip("\n")) return self.stderr.write(json.dumps(payload) + "\n") - def flush(self): - pass - def _http_view_func_wrapper(function, request): def view_func(path):