diff --git a/.github/.OwlBot.lock.yaml b/.github/.OwlBot.lock.yaml index b2770d4e..6301519a 100644 --- a/.github/.OwlBot.lock.yaml +++ b/.github/.OwlBot.lock.yaml @@ -13,5 +13,5 @@ # limitations under the License. docker: image: gcr.io/cloud-devrel-public-resources/owlbot-python:latest - digest: sha256:91d0075c6f2fd6a073a06168feee19fa2a8507692f2519a1dc7de3366d157e99 -# created: 2024-11-11T16:13:09.302418532Z + digest: sha256:2ed982f884312e4883e01b5ab8af8b6935f0216a5a2d82928d273081fc3be562 +# created: 2024-11-12T12:09:45.821174897Z diff --git a/.kokoro/docker/docs/requirements.txt b/.kokoro/docker/docs/requirements.txt index 66eacc82..8bb07645 100644 --- a/.kokoro/docker/docs/requirements.txt +++ b/.kokoro/docker/docs/requirements.txt @@ -1,5 +1,5 @@ # -# This file is autogenerated by pip-compile with Python 3.9 +# This file is autogenerated by pip-compile with Python 3.10 # by the following command: # # pip-compile --allow-unsafe --generate-hashes requirements.in @@ -8,9 +8,9 @@ argcomplete==3.5.1 \ --hash=sha256:1a1d148bdaa3e3b93454900163403df41448a248af01b6e849edc5ac08e6c363 \ --hash=sha256:eb1ee355aa2557bd3d0145de7b06b2a45b0ce461e1e7813f5d066039ab4177b4 # via nox -colorlog==6.8.2 \ - --hash=sha256:3e3e079a41feb5a1b64f978b5ea4f46040a94f11f0e8bbb8261e3dbbeca64d44 \ - --hash=sha256:4dcbb62368e2800cb3c5abd348da7e53f6c362dda502ec27c560b2e58a66bd33 +colorlog==6.9.0 \ + --hash=sha256:5906e71acd67cb07a71e779c47c4bcb45fb8c2993eebe9e5adcd6a6f1b283eff \ + --hash=sha256:bfba54a1b93b94f54e1f4fe48395725a3d92fd2a4af702f6bd70946bdc0c6ac2 # via nox distlib==0.3.9 \ --hash=sha256:47f8c22fd27c27e25a65601af709b38e4f0a45ea4fc2e710f65755fa8caaaf87 \ @@ -24,9 +24,9 @@ nox==2024.10.9 \ --hash=sha256:1d36f309a0a2a853e9bccb76bbef6bb118ba92fa92674d15604ca99adeb29eab \ --hash=sha256:7aa9dc8d1c27e9f45ab046ffd1c3b2c4f7c91755304769df231308849ebded95 # via -r requirements.in -packaging==24.1 \ - --hash=sha256:026ed72c8ed3fcce5bf8950572258698927fd1dbda10a5e981cdf0ac37f4f002 \ - --hash=sha256:5b8f2217dbdbd2f7f384c41c628544e6d52f2d0f53c6d0c3ea61aa5d1d7ff124 +packaging==24.2 \ + --hash=sha256:09abb1bccd265c01f4a3aa3f7a7db064b36514d2cba19a2f694fe6150451a759 \ + --hash=sha256:c228a6dc5e932d346bc5739379109d49e8853dd8223571c7c5b55260edc0b97f # via nox platformdirs==4.3.6 \ --hash=sha256:357fb2acbc885b0419afd3ce3ed34564c13c9b95c89360cd9563f73aa5e2b907 \ @@ -36,7 +36,7 @@ tomli==2.0.2 \ --hash=sha256:2ebe24485c53d303f690b0ec092806a085f07af5a5aa1464f3931eec36caaa38 \ --hash=sha256:d46d457a85337051c36524bc5349dd91b1877838e2979ac5ced3e710ed8a60ed # via nox -virtualenv==20.26.6 \ - --hash=sha256:280aede09a2a5c317e409a00102e7077c6432c5a38f0ef938e643805a7ad2c48 \ - --hash=sha256:7345cc5b25405607a624d8418154577459c3e0277f5466dd79c49d5e492995f2 +virtualenv==20.27.1 \ + --hash=sha256:142c6be10212543b32c6c45d3d3893dff89112cc588b7d0879ae5a1ec03a47ba \ + --hash=sha256:f11f1b8a29525562925f745563bfd48b189450f61fb34c4f9cc79dd5aa32a1f4 # via nox diff --git a/CHANGELOG.md b/CHANGELOG.md index 060a0a86..c7eacaf0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,14 @@ [1]: https://pypi.org/project/google-api-core/#history +## [2.24.0](https://github.com/googleapis/python-api-core/compare/v2.23.0...v2.24.0) (2024-12-06) + + +### Features + +* Add automatic logging config to support debug logging ([#754](https://github.com/googleapis/python-api-core/issues/754)) ([d18d9b5](https://github.com/googleapis/python-api-core/commit/d18d9b5131162b44eebcc0859a7aca1198a2ac06)) +* Update recognized logging fields ([#766](https://github.com/googleapis/python-api-core/issues/766)) ([5f80f77](https://github.com/googleapis/python-api-core/commit/5f80f778bc25d878b3187c6138077ad8c6bcd35f)) + ## [2.23.0](https://github.com/googleapis/python-api-core/compare/v2.22.0...v2.23.0) (2024-11-11) diff --git a/google/api_core/client_logging.py b/google/api_core/client_logging.py new file mode 100644 index 00000000..837e3e0c --- /dev/null +++ b/google/api_core/client_logging.py @@ -0,0 +1,144 @@ +import logging +import json +import os + +from typing import List, Optional + +_LOGGING_INITIALIZED = False +_BASE_LOGGER_NAME = "google" + +# Fields to be included in the StructuredLogFormatter. +# +# TODO(https://github.com/googleapis/python-api-core/issues/761): Update this list to support additional logging fields. +_recognized_logging_fields = [ + "httpRequest", + "rpcName", + "serviceName", + "credentialsType", + "credentialsInfo", + "universeDomain", + "request", + "response", + "metadata", + "retryAttempt", + "httpResponse", +] # Additional fields to be Logged. + + +def logger_configured(logger) -> bool: + """Determines whether `logger` has non-default configuration + + Args: + logger: The logger to check. + + Returns: + bool: Whether the logger has any non-default configuration. + """ + return ( + logger.handlers != [] or logger.level != logging.NOTSET or not logger.propagate + ) + + +def initialize_logging(): + """Initializes "google" loggers, partly based on the environment variable + + Initializes the "google" logger and any loggers (at the "google" + level or lower) specified by the environment variable + GOOGLE_SDK_PYTHON_LOGGING_SCOPE, as long as none of these loggers + were previously configured. If any such loggers (including the + "google" logger) are initialized, they are set to NOT propagate + log events up to their parent loggers. + + This initialization is executed only once, and hence the + environment variable is only processed the first time this + function is called. + """ + global _LOGGING_INITIALIZED + if _LOGGING_INITIALIZED: + return + scopes = os.getenv("GOOGLE_SDK_PYTHON_LOGGING_SCOPE", "") + setup_logging(scopes) + _LOGGING_INITIALIZED = True + + +def parse_logging_scopes(scopes: Optional[str] = None) -> List[str]: + """Returns a list of logger names. + + Splits the single string of comma-separated logger names into a list of individual logger name strings. + + Args: + scopes: The name of a single logger. (In the future, this will be a comma-separated list of multiple loggers.) + + Returns: + A list of all the logger names in scopes. + """ + if not scopes: + return [] + # TODO(https://github.com/googleapis/python-api-core/issues/759): check if the namespace is a valid namespace. + # TODO(b/380481951): Support logging multiple scopes. + # TODO(b/380483756): Raise or log a warning for an invalid scope. + namespaces = [scopes] + return namespaces + + +def configure_defaults(logger): + """Configures `logger` to emit structured info to stdout.""" + if not logger_configured(logger): + console_handler = logging.StreamHandler() + logger.setLevel("DEBUG") + logger.propagate = False + formatter = StructuredLogFormatter() + console_handler.setFormatter(formatter) + logger.addHandler(console_handler) + + +def setup_logging(scopes: str = ""): + """Sets up logging for the specified `scopes`. + + If the loggers specified in `scopes` have not been previously + configured, this will configure them to emit structured log + entries to stdout, and to not propagate their log events to their + parent loggers. Additionally, if the "google" logger (whether it + was specified in `scopes` or not) was not previously configured, + it will also configure it to not propagate log events to the root + logger. + + Args: + scopes: The name of a single logger. (In the future, this will be a comma-separated list of multiple loggers.) + + """ + + # only returns valid logger scopes (namespaces) + # this list has at most one element. + logger_names = parse_logging_scopes(scopes) + + for namespace in logger_names: + # This will either create a module level logger or get the reference of the base logger instantiated above. + logger = logging.getLogger(namespace) + + # Configure default settings. + configure_defaults(logger) + + # disable log propagation at base logger level to the root logger only if a base logger is not already configured via code changes. + base_logger = logging.getLogger(_BASE_LOGGER_NAME) + if not logger_configured(base_logger): + base_logger.propagate = False + + +# TODO(https://github.com/googleapis/python-api-core/issues/763): Expand documentation. +class StructuredLogFormatter(logging.Formatter): + # TODO(https://github.com/googleapis/python-api-core/issues/761): ensure that additional fields such as + # function name, file name, and line no. appear in a log output. + def format(self, record: logging.LogRecord): + log_obj = { + "timestamp": self.formatTime(record), + "severity": record.levelname, + "name": record.name, + "message": record.getMessage(), + } + + for field_name in _recognized_logging_fields: + value = getattr(record, field_name, None) + if value is not None: + log_obj[field_name] = value + return json.dumps(log_obj) diff --git a/google/api_core/version.py b/google/api_core/version.py index 416bf20e..84f6b464 100644 --- a/google/api_core/version.py +++ b/google/api_core/version.py @@ -12,4 +12,4 @@ # See the License for the specific language governing permissions and # limitations under the License. -__version__ = "2.23.0" +__version__ = "2.24.0" diff --git a/tests/unit/test_client_logging.py b/tests/unit/test_client_logging.py new file mode 100644 index 00000000..b3b0b5c8 --- /dev/null +++ b/tests/unit/test_client_logging.py @@ -0,0 +1,140 @@ +import json +import logging +from unittest import mock + +from google.api_core.client_logging import ( + setup_logging, + initialize_logging, + StructuredLogFormatter, +) + + +def reset_logger(scope): + logger = logging.getLogger(scope) + logger.handlers = [] + logger.setLevel(logging.NOTSET) + logger.propagate = True + + +def test_setup_logging_w_no_scopes(): + with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foogle"): + setup_logging() + base_logger = logging.getLogger("foogle") + assert base_logger.handlers == [] + assert not base_logger.propagate + assert base_logger.level == logging.NOTSET + + reset_logger("foogle") + + +def test_setup_logging_w_base_scope(): + with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foogle"): + setup_logging("foogle") + base_logger = logging.getLogger("foogle") + assert isinstance(base_logger.handlers[0], logging.StreamHandler) + assert not base_logger.propagate + assert base_logger.level == logging.DEBUG + + reset_logger("foogle") + + +def test_setup_logging_w_configured_scope(): + with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foogle"): + base_logger = logging.getLogger("foogle") + base_logger.propagate = False + setup_logging("foogle") + assert base_logger.handlers == [] + assert not base_logger.propagate + assert base_logger.level == logging.NOTSET + + reset_logger("foogle") + + +def test_setup_logging_w_module_scope(): + with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foogle"): + setup_logging("foogle.bar") + + base_logger = logging.getLogger("foogle") + assert base_logger.handlers == [] + assert not base_logger.propagate + assert base_logger.level == logging.NOTSET + + module_logger = logging.getLogger("foogle.bar") + assert isinstance(module_logger.handlers[0], logging.StreamHandler) + assert not module_logger.propagate + assert module_logger.level == logging.DEBUG + + reset_logger("foogle") + reset_logger("foogle.bar") + + +def test_setup_logging_w_incorrect_scope(): + with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foogle"): + setup_logging("abc") + + base_logger = logging.getLogger("foogle") + assert base_logger.handlers == [] + assert not base_logger.propagate + assert base_logger.level == logging.NOTSET + + # TODO(https://github.com/googleapis/python-api-core/issues/759): update test once we add logic to ignore an incorrect scope. + logger = logging.getLogger("abc") + assert isinstance(logger.handlers[0], logging.StreamHandler) + assert not logger.propagate + assert logger.level == logging.DEBUG + + reset_logger("foogle") + reset_logger("abc") + + +def test_initialize_logging(): + + with mock.patch("os.getenv", return_value="foogle.bar"): + with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foogle"): + initialize_logging() + + base_logger = logging.getLogger("foogle") + assert base_logger.handlers == [] + assert not base_logger.propagate + assert base_logger.level == logging.NOTSET + + module_logger = logging.getLogger("foogle.bar") + assert isinstance(module_logger.handlers[0], logging.StreamHandler) + assert not module_logger.propagate + assert module_logger.level == logging.DEBUG + + # Check that `initialize_logging()` is a no-op after the first time by verifying that user-set configs are not modified: + base_logger.propagate = True + module_logger.propagate = True + + initialize_logging() + + assert base_logger.propagate + assert module_logger.propagate + + reset_logger("foogle") + reset_logger("foogle.bar") + + +def test_structured_log_formatter(): + # TODO(https://github.com/googleapis/python-api-core/issues/761): Test additional fields when implemented. + record = logging.LogRecord( + name="Appelation", + level=logging.DEBUG, + msg="This is a test message.", + pathname="some/path", + lineno=25, + args=None, + exc_info=None, + ) + + # Extra fields: + record.rpcName = "bar" + + formatted_msg = StructuredLogFormatter().format(record) + parsed_msg = json.loads(formatted_msg) + + assert parsed_msg["name"] == "Appelation" + assert parsed_msg["severity"] == "DEBUG" + assert parsed_msg["message"] == "This is a test message." + assert parsed_msg["rpcName"] == "bar"