Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ensure the log messages from operators during parsing go somewhere #26779

Merged
merged 5 commits into from Sep 30, 2022

Conversation

ashb
Copy link
Member

@ashb ashb commented Sep 29, 2022

While investigating #26599 and the change from AIP-45, I noticed that these warning messages weren't new! The only thing that was new was that we started seeing them.

This is because the logger for BaseOperator and all subclasses is airflow.task.operators, and the airflow.task logger is not configured (with set_context()) until we have a TaskInstance, so it just dropped all messages on the floor!

This changes it so that log messages are propagated to parent loggers by default, but when we configure a context (and thus have a file to write to) we stop that. A similar change was made for the airflow.processor (but that is unlikely to suffer the same fate)

@ashb
Copy link
Member Author

ashb commented Sep 29, 2022

We shouldn't merge this to a release until we also fix the source of the issue (which is a bug, not user error)

While investigating apache#26599 and the change from AIP-45, I noticed that
these warning messages weren't new! The only thing that was new was that
we started seeing them.

This is because the logger for BaseOperator and all subclasses is
`airflow.task.operators`, and the `airflow.task` logger is not
configured (with `set_context()`) until we have a TaskInstance, so it
just dropped all messages on the floor!

This changes it so that log messages are propagated to parent loggers by
default, but when we configure a context (and thus have a file to write
to) we stop that. A similar change was made for the `airflow.processor`
(but that is unlikely to suffer the same fate)
@ashb ashb force-pushed the task_logs_should_go_somewhere branch from e2d19c5 to fba879e Compare September 29, 2022 15:43
airflow/utils/log/logging_mixin.py Outdated Show resolved Hide resolved
airflow/utils/log/logging_mixin.py Outdated Show resolved Hide resolved
The ArangoDB sensor test was logging a mock object, which previously was
getting dropped before emitting, but with this change now fails with
"Mock is not an integer" when attempting the  `%d` intepolation.

To avoid making the mock overly specific (`arangodb_client_for_test.db.`
`return_value.aql.execute.return_value.count.return_value`!) I have
changed the test to mock the hook entirely (which is already tested)
@ashb ashb merged commit 7363e35 into apache:main Sep 30, 2022
@ashb ashb deleted the task_logs_should_go_somewhere branch September 30, 2022 13:08
@ashb ashb added this to the Airflow 2.4.2 milestone Sep 30, 2022
@ephraimbuddy ephraimbuddy added the type:bug-fix Changelog: Bug Fixes label Oct 18, 2022
ephraimbuddy pushed a commit that referenced this pull request Oct 18, 2022
…26779)

* Ensure the log messages from operators during parsing go somewhere

While investigating #26599 and the change from AIP-45, I noticed that
these warning messages weren't new! The only thing that was new was that
we started seeing them.

This is because the logger for BaseOperator and all subclasses is
`airflow.task.operators`, and the `airflow.task` logger is not
configured (with `set_context()`) until we have a TaskInstance, so it
just dropped all messages on the floor!

This changes it so that log messages are propagated to parent loggers by
default, but when we configure a context (and thus have a file to write
to) we stop that. A similar change was made for the `airflow.processor`
(but that is unlikely to suffer the same fate)

* Give a real row count value so logs don't fail

The ArangoDB sensor test was logging a mock object, which previously was
getting dropped before emitting, but with this change now fails with
"Mock is not an integer" when attempting the  `%d` interpolation.

To avoid making the mock overly specific (`arangodb_client_for_test.db.`
`return_value.aql.execute.return_value.count.return_value`!) I have
changed the test to mock the hook entirely (which is already tested)

(cherry picked from commit 7363e35)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area:logging type:bug-fix Changelog: Bug Fixes
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants