kaxil commented on code in PR #66633: URL: https://github.com/apache/airflow/pull/66633#discussion_r3707284685
########## task-sdk/tests/task_sdk/test_log.py: ########## @@ -0,0 +1,166 @@ +# +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you 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. +from __future__ import annotations + +from unittest import mock + +import structlog +import structlog.testing +from uuid6 import uuid7 + +from airflow.sdk import log as sdk_log + + +def _make_ti(): + ti = mock.MagicMock() + ti.id = uuid7() + return ti + + +def _make_logger(): + """Build a FilteringBoundLogger-like object exposing ``_logger``.""" + logger = mock.MagicMock() + logger._logger = mock.MagicMock() + return logger + + +class TestUploadToRemote: Review Comment: The three test_warns_* tests in this class fail at HEAD, see the Task SDK job: https://github.com/apache/airflow/actions/runs/30734933337/job/91463012820. They assert warning events (remote_log_handler_unavailable, remote_log_path_resolution_failed, remote_log_upload_failed) that only existed in the earlier revision of this PR; after the scope-down nothing emits them, and upload_to_remote doesn't catch upload errors, so test_warns_when_upload_fails fails with the raw RuntimeError. The Glue test you mentioned is a different job, this failure comes from this file. I'd drop these three and keep the two test_silent_* tests plus the dictConfig regression test, which do match current behavior. ########## task-sdk/src/airflow/sdk/log.py: ########## @@ -119,8 +119,14 @@ def configure_logging( if mask_secrets: extra_processors += (mask_logs,) - if (remote := load_remote_log_handler()) and (remote_processors := getattr(remote, "processors")): - extra_processors += remote_processors + # NOTE: Do NOT call getattr(remote, "processors") here. + # Accessing remote.processors triggers creation of the remote handler + # via a cached_property. The configure_logging() call below runs dictConfig() internally, Review Comment: The "Done. Thanks" replies from Aug 2 don't appear to be in the branch, the last commit (3217a41) predates @jason810496's comments: this line still mentions the cached_property, and the two assert-style nits in test_log.py are unchanged. Could you push the commit with those changes? The threads are marked resolved, so this is easy to miss otherwise. ########## task-sdk/tests/task_sdk/test_log.py: ########## @@ -0,0 +1,166 @@ +# +# Licensed to the Apache Software Foundation (ASF) under one +# or more contributor license agreements. See the NOTICE file +# distributed with this work for additional information +# regarding copyright ownership. The ASF licenses this file +# to you 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. +from __future__ import annotations + +from unittest import mock + +import structlog +import structlog.testing +from uuid6 import uuid7 + +from airflow.sdk import log as sdk_log + + +def _make_ti(): + ti = mock.MagicMock() + ti.id = uuid7() + return ti + + +def _make_logger(): + """Build a FilteringBoundLogger-like object exposing ``_logger``.""" + logger = mock.MagicMock() + logger._logger = mock.MagicMock() + return logger + + +class TestUploadToRemote: + def test_warns_when_handler_unavailable(self): + ti = _make_ti() + with ( + mock.patch.object(sdk_log, "load_remote_log_handler", return_value=None), + structlog.testing.capture_logs() as captured, + ): + sdk_log.upload_to_remote(_make_logger(), ti) + + events = [e for e in captured if e["event"] == "remote_log_handler_unavailable"] + assert len(events) == 1 + assert events[0]["log_level"] == "warning" + assert events[0]["ti_id"] == str(ti.id) + + def test_warns_when_path_resolution_fails(self): + ti = _make_ti() + handler = mock.MagicMock() + boom = RuntimeError("cannot resolve path") + with ( + mock.patch.object(sdk_log, "load_remote_log_handler", return_value=handler), + mock.patch.object(sdk_log, "relative_path_from_logger", side_effect=boom), + structlog.testing.capture_logs() as captured, + ): + sdk_log.upload_to_remote(_make_logger(), ti) + + events = [e for e in captured if e["event"] == "remote_log_path_resolution_failed"] + assert len(events) == 1 + assert events[0]["log_level"] == "warning" + assert events[0]["ti_id"] == str(ti.id) + assert events[0]["exc_info"] is boom + handler.upload.assert_not_called() + + def test_warns_when_upload_fails(self, tmp_path): + ti = _make_ti() + handler = mock.MagicMock() + boom = RuntimeError("s3 unreachable") + handler.upload.side_effect = boom + relative = tmp_path / "dag_id" / "run_id" / "task.log" + with ( + mock.patch.object(sdk_log, "load_remote_log_handler", return_value=handler), + mock.patch.object(sdk_log, "relative_path_from_logger", return_value=relative), + structlog.testing.capture_logs() as captured, + ): + sdk_log.upload_to_remote(_make_logger(), ti) + + events = [e for e in captured if e["event"] == "remote_log_upload_failed"] + assert len(events) == 1 + assert events[0]["log_level"] == "warning" + assert events[0]["ti_id"] == str(ti.id) + assert events[0]["log_relative_path"] == relative.as_posix() + assert events[0]["exc_info"] is boom + handler.upload.assert_called_once_with(relative.as_posix(), ti) + + def test_silent_when_relative_path_is_none(self): + ti = _make_ti() + handler = mock.MagicMock() + with ( + mock.patch.object(sdk_log, "load_remote_log_handler", return_value=handler), + mock.patch.object(sdk_log, "relative_path_from_logger", return_value=None), + structlog.testing.capture_logs() as captured, + ): + sdk_log.upload_to_remote(_make_logger(), ti) + + assert captured == [] + handler.upload.assert_not_called() + + def test_silent_on_success(self, tmp_path): + ti = _make_ti() + handler = mock.MagicMock() + relative = tmp_path / "dag_id" / "run_id" / "task.log" + with ( + mock.patch.object(sdk_log, "load_remote_log_handler", return_value=handler), + mock.patch.object(sdk_log, "relative_path_from_logger", return_value=relative), + structlog.testing.capture_logs() as captured, + ): + sdk_log.upload_to_remote(_make_logger(), ti) + + assert captured == [] + handler.upload.assert_called_once_with(relative.as_posix(), ti) + + +class TestConfigureLogging: + def test_remote_processors_injected_after_dictconfig(self): + """ + Regression test: remote processor injection must happen AFTER dictConfig() runs. + + dictConfig()'s non-incremental reset closes every handler in + logging._handlerList. If the remote handler is built before dictConfig + runs, it is closed before any task log is emitted and silently drops + all records. + """ + import airflow.sdk._shared.logging as shared_logging + + call_order = [] + + mock_handler = mock.MagicMock() + mock_handler.processors = (mock.MagicMock(),) + + def track_load_remote(): + call_order.append("load_remote_log_handler") + return mock_handler + + original_inner = shared_logging.configure_logging + + def track_inner_configure(*args, **kwargs): + call_order.append("dictConfig") + return original_inner(*args, **kwargs) + + # configure_logging is @cache decorated — clear it so the test actually runs the function + sdk_log.configure_logging.cache_clear() Review Comment: This test leaves global state behind: the configure_logging cache is cleared but never restored, and the real structlog.configure call inside puts mock_handler's MagicMock processor into the live global chain, where it stays for every later test in the process until something reconfigures logging. Restoring the previous processors in a finally (the way captured_logs in conftest.py does) and clearing the cache again on the way out would keep it isolated. -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
