Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading
, 'i'); if (__m === '*' || __re.test(location.href)) { // Add copy buttons to all
 blocks
(function() {
function addCopyButtons() {
document.querySelectorAll('pre code').forEach(function(codeBlock) {
if (codeBlock.parentElement.hasAttribute('data-copy-added')) return;
codeBlock.parentElement.setAttribute('data-copy-added', 'true');
var btn = document.createElement('button');
btn.textContent = 'Copy';
btn.style.cssText = 'position:absolute;top:4px;right:4px;padding:2px 8px;font-size:11px;background:#4ecdc4;border:none;border-radius:4px;color:#1a1a2e;cursor:pointer;opacity:0.7;transition:opacity 0.2s;';
btn.onmouseover = function() { this.style.opacity = '1'; };
btn.onmouseout = function() { this.style.opacity = '0.7'; };
btn.onclick = function() {
navigator.clipboard.writeText(codeBlock.textContent).then(function() {
btn.textContent = 'Copied!';
setTimeout(function() { btn.textContent = 'Copy'; }, 1500);
});
};
codeBlock.parentElement.style.position = 'relative';
codeBlock.parentElement.appendChild(btn);
});
}
addCopyButtons();
// Re-run on dynamic content
var observer = new MutationObserver(addCopyButtons);
observer.observe(document.body, { childList: true, subtree: true });
})();
}
} catch(__e) { console.warn('[Userscript:Add Copy Buttons to Code Blocks]', __e); }
})();
(function(){
try {
var __m = "github.com";
var __re = new RegExp('^' + "github\\.com" + '
Include hook name in suppressed listener-exception log by 1fanwang · Pull Request #66395 · apache/airflow · GitHub
Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading
, 'i'); if (__m === '*' || __re.test(location.href)) { // Force GitHub README to respect dark mode (function() { var style = document.createElement('style'); style.textContent = ' .markdown-body { color-scheme: dark light; } .markdown-body pre { background: #161b22 !important; } .markdown-body code { background: rgba(110, 118, 129, 0.4) !important; } .markdown-body table th, .markdown-body table td { border-color: #30363d !important; } .markdown-body img { background: #0d1117; } .markdown-body blockquote { border-left-color: #8b949e; } .markdown-body hr { border-color: #30363d; } '; document.head.appendChild(style); })(); } } catch(__e) { console.warn('[Userscript:GitHub Dark Mode README Fix]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + ' Include hook name in suppressed listener-exception log by 1fanwang · Pull Request #66395 · apache/airflow · GitHub
Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading
, 'i'); if (__m === '*' || __re.test(location.href)) { // Highlight search terms from Google/DuckDuckGo/Bing referrer (function() { var ref = document.referrer; var terms = []; if (ref.includes('google.com') || ref.includes('duckduckgo.com') || ref.includes('bing.com')) { var url = new URL(ref); var q = url.searchParams.get('q') || url.searchParams.get('p'); if (q) { terms = q.split(/\s+/).filter(function(t) { return t.length > 2; }); } } if (terms.length === 0) return; var style = document.createElement('style'); style.textContent = '.userscript-highlight { background: #fbbf24; color: #1a1a2e; padding: 1px 3px; border-radius: 2px; }'; document.head.appendChild(style); function highlight(node) { if (node.nodeType === 3) { // text node var text = node.textContent; var found = false; terms.forEach(function(term) { var regex = new RegExp('(' + term.replace(/[.*+?^${}()|[\]\\]/g, '\\') + ')', 'gi'); if (regex.test(text)) { found = true; var frag = document.createDocumentFragment(); var parts = text.split(regex); parts.forEach(function(part, i) { if (i % 2 === 0) { frag.appendChild(document.createTextNode(part)); } else { var span = document.createElement('span'); span.className = 'userscript-highlight'; span.textContent = part; frag.appendChild(span); } }); node.parentNode.replaceChild(frag, node); } }); } else if (node.nodeType === 1 && node.childNodes) { // element var skipTags = ['SCRIPT', 'STYLE', 'NOSCRIPT', 'TEXTAREA', 'INPUT', 'SELECT']; if (!skipTags.includes(node.tagName)) { Array.from(node.childNodes).forEach(highlight); } } } highlight(document.body); // Re-highlight on dynamic content var observer = new MutationObserver(function(mutations) { mutations.forEach(function(m) { m.addedNodes.forEach(function(node) { if (node.nodeType === 1 || node.nodeType === 3) highlight(node); }); }); }); observer.observe(document.body, { childList: true, subtree: true }); })(); } } catch(__e) { console.warn('[Userscript:Highlight Search Terms]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + ' Include hook name in suppressed listener-exception log by 1fanwang · Pull Request #66395 · apache/airflow · GitHub
Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading
, 'i'); if (__m === '*' || __re.test(location.href)) { // Strip utm_, fbclid, gclid, etc. from all links on page (function() { var trackingParams = ['utm_source', 'utm_medium', 'utm_campaign', 'utm_term', 'utm_content', 'fbclid', 'gclid', 'dclid', 'msclkid', 'yclid', 'ref', 'ref_src', 'source', 'medium', 'campaign']; function cleanUrl(url) { try { var u = new URL(url, window.location.origin); var changed = false; trackingParams.forEach(function(p) { if (u.searchParams.has(p)) { u.searchParams.delete(p); changed = true; } }); return changed ? u.toString() : url; } catch (e) { return url; } } function cleanLinks() { document.querySelectorAll('a[href]').forEach(function(a) { var clean = cleanUrl(a.href); if (clean !== a.href) a.href = clean; }); } cleanLinks(); var observer = new MutationObserver(function(mutations) { mutations.forEach(function(m) { m.addedNodes.forEach(function(node) { if (node.nodeType === 1) { if (node.tagName === 'A') cleanLinks(); node.querySelectorAll('a[href]').forEach(function(a) { var clean = cleanUrl(a.href); if (clean !== a.href) a.href = clean; }); } }); }); }); observer.observe(document.body, { childList: true, subtree: true }); })(); } } catch(__e) { console.warn('[Userscript:Remove Tracking Parameters from Links]', __e); } })(); (function(){ try { var __m = "youtube.com"; var __re = new RegExp('^' + "youtube\\.com" + ' Include hook name in suppressed listener-exception log by 1fanwang · Pull Request #66395 · apache/airflow · GitHub
Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading
, 'i'); if (__m === '*' || __re.test(location.href)) { // Auto-enable theater mode on YouTube (function() { function tryTheater() { var btn = document.querySelector('button[aria-label="Theater mode"], ytd-player #player button[title="Theater mode"]'); if (btn && !btn.classList.contains('activated')) { btn.click(); } } // Try immediately tryTheater(); // Try after navigation (SPA) var lastUrl = location.href; setInterval(function() { if (location.href !== lastUrl) { lastUrl = location.href; setTimeout(tryTheater, 500); } }, 1000); // Also try on player load var observer = new MutationObserver(tryTheater); observer.observe(document.body, { childList: true, subtree: true }); })(); } } catch(__e) { console.warn('[Userscript:YouTube Theater Mode Default]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + ' Include hook name in suppressed listener-exception log by 1fanwang · Pull Request #66395 · apache/airflow · GitHub
Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading
, 'i'); if (__m === '*' || __re.test(location.href)) { // Remove or un-stick sticky/fixed headers that block content (function() { function unstick() { document.querySelectorAll('header, nav, [role="banner"], .header, .navbar, .sticky, .fixed-top, [style*="position: fixed"], [style*="position:sticky"]').forEach(function(el) { if (el.style.position === 'fixed' || el.style.position === 'sticky' || getComputedStyle(el).position === 'fixed' || getComputedStyle(el).position === 'sticky') { el.style.position = 'static'; el.style.top = 'auto'; el.style.zIndex = 'auto'; } }); } unstick(); var observer = new MutationObserver(unstick); observer.observe(document.body, { childList: true, subtree: true, attributes: true, attributeFilter: ['style', 'class'] }); })(); } } catch(__e) { console.warn('[Userscript:Kill Sticky Headers]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + ' Include hook name in suppressed listener-exception log by 1fanwang · Pull Request #66395 · apache/airflow · GitHub
Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading
, 'i'); if (__m === '*' || __re.test(location.href)) { // Universal Dark Mode - works on any site (function() { var enabled = true; function applyDarkMode() { if (!enabled) return; // Create style element if it doesn't exist var style = document.getElementById('universal-dark-mode-style'); if (!style) { style = document.createElement('style'); style.id = 'universal-dark-mode-style'; document.head.appendChild(style); } // Dark mode CSS - inverts colors but preserves images/video style.textContent = ' /* Invert everything except media */ html { filter: invert(1) hue-rotate(180deg) !important; background: #1a1a2e !important; } /* Restore images, videos, iframes, canvas */ img, video, iframe, canvas, svg, picture, [style*="background-image"] { filter: invert(1) hue-rotate(180deg) !important; } /* Preserve specific elements that should not be inverted */ .no-dark-mode, .no-dark-mode *, [data-theme="light"], [data-theme="light"], .ace_editor, .ace_editor *, .CodeMirror, .CodeMirror *, .monaco-editor, .monaco-editor *, .markdown-body pre, .markdown-body pre *, .highlight, .highlight *, pre code, pre code * { filter: none !important; } /* Fix common UI elements */ .modal, .popup, .dropdown-menu, .tooltip, .popover { filter: invert(1) hue-rotate(180deg) !important; background: #2d2d44 !important; border-color: #444 !important; } /* Scrollbars */ ::-webkit-scrollbar { background: #1a1a2e !important; } ::-webkit-scrollbar-thumb { background: #444 !important; } ::-webkit-scrollbar-thumb:hover { background: #555 !important; } /* Selection */ ::selection { background: #4ecdc4 !important; color: #1a1a2e !important; } ::-moz-selection { background: #4ecdc4 !important; color: #1a1a2e !important; } '; } function removeDarkMode() { var style = document.getElementById('universal-dark-mode-style'); if (style) style.remove(); } // Toggle with Alt+Shift+D document.addEventListener('keydown', function(e) { if (e.altKey && e.shiftKey && e.key === 'D') { e.preventDefault(); enabled = !enabled; if (enabled) { applyDarkMode(); console.log('[Universal Dark Mode] Enabled'); } else { removeDarkMode(); console.log('[Universal Dark Mode] Disabled'); } } }); // Apply on load applyDarkMode(); // Re-apply on dynamic content var observer = new MutationObserver(function(mutations) { if (enabled && !document.getElementById('universal-dark-mode-style')) { applyDarkMode(); } }); observer.observe(document.head, { childList: true }); console.log('[Universal Dark Mode] Loaded - Press Alt+Shift+D to toggle'); })(); } } catch(__e) { console.warn('[Userscript:Universal Dark Mode]', __e); } })(); })(); Include hook name in suppressed listener-exception log by 1fanwang · Pull Request #66395 · apache/airflow · GitHub
Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions airflow-core/newsfragments/66395.misc.rst
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
Suppressed task instance listener exceptions now log the failing hook name as a structured field.
Original file line numberDiff line numberDiff line change
Expand Up@@ -76,19 +76,25 @@ def _validate_patch_task_instance_body(
def _emit_state_listener_hooks(updated_tis: list[TI], new_state: str | TaskInstanceState) -> None:
"""Fire listener hooks for the given TIs based on their new state. Listener errors are logged."""
for ti in updated_tis:
try:
if new_state == TaskInstanceState.SUCCESS:
if new_state == TaskInstanceState.SUCCESS:
try:
get_listener_manager().hook.on_task_instance_success(previous_state=None, task_instance=ti)
elif new_state == TaskInstanceState.FAILED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif new_state == TaskInstanceState.FAILED:
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=None,
task_instance=ti,
error=f"TaskInstance's state was manually set to `{TaskInstanceState.FAILED}`.",
)
elif new_state == TaskInstanceState.SKIPPED:
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_failed")
elif new_state == TaskInstanceState.SKIPPED:
try:
get_listener_manager().hook.on_task_instance_skipped(previous_state=None, task_instance=ti)
except Exception:
log.exception("error calling listener")
except Exception:
log.exception("error calling listener for hook %r", "on_task_instance_skipped")


def _reload_tis_with_rendered_fields(tis: list[TI], session: Session) -> list[TI]:
Expand Down
2 changes: 1 addition & 1 deletion airflow-core/src/airflow/models/taskinstance.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1776,7 +1776,7 @@ def fetch_handle_failure_context(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")

return ti

Expand Down
2 changes: 1 addition & 1 deletion airflow-core/tests/unit/listeners/test_listeners.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -118,7 +118,7 @@ def test_listener_suppresses_exceptions(create_task_instance, session, cap_struc

ti = create_task_instance(session=session, state=TaskInstanceState.QUEUED)
ti.run()
assert "error calling listener" in cap_structlog
assert "error calling listener for hook 'on_task_instance_success'" in cap_structlog


@provide_session
Expand Down
10 changes: 5 additions & 5 deletions task-sdk/src/airflow/sdk/execution_time/task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -1178,7 +1178,7 @@ def _prepare(ti: RuntimeTaskInstance, log: Logger, context: Context) -> ToSuperv
previous_state=TaskInstanceState.QUEUED, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_running")

# No error, carry on and execute the task
return None
Expand DownExpand Up@@ -1903,23 +1903,23 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_success")
elif state == TaskInstanceState.SKIPPED:
_run_task_state_change_callbacks(task, "on_skipped_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_skipped(
previous_state=TaskInstanceState.RUNNING, task_instance=ti
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_skipped")
elif state == TaskInstanceState.UP_FOR_RETRY:
_run_task_state_change_callbacks(task, "on_retry_callback", context, log)
try:
get_listener_manager().hook.on_task_instance_failed(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_retry and task.email:
_send_error_email_notification(task, ti, context, error, log)
elif state == TaskInstanceState.FAILED:
Expand All@@ -1929,7 +1929,7 @@ def finalize(
previous_state=TaskInstanceState.RUNNING, task_instance=ti, error=error
)
except Exception:
log.exception("error calling listener")
log.exception("error calling listener for hook %r", "on_task_instance_failed")
if error and task.email_on_failure and task.email:
_send_error_email_notification(task, ti, context, error, log)

Expand Down
37 changes: 37 additions & 0 deletions task-sdk/tests/task_sdk/execution_time/test_task_runner.py
Original file line numberDiff line numberDiff line change
Expand Up@@ -3941,6 +3941,43 @@ def execute(self, context):

assert listener.state == [TaskInstanceState.RUNNING, TaskInstanceState.SUCCESS]

def test_listener_error_log_includes_hook_name(
self, mocked_parse, mock_supervisor_comms, listener_manager
):
"""When a listener hook raises, the exception log must identify which hook
raised so plugin authors can debug across multiple registered listeners."""

class ThrowingListener:
@hookimpl
def on_task_instance_success(self, previous_state, task_instance):
raise RuntimeError("listener boom")

listener_manager(ThrowingListener())

class CustomOperator(BaseOperator):
def execute(self, context):
pass

task = CustomOperator(task_id="test_listener_error_log_includes_hook_name")
dag = get_inline_dag(dag_id="test_dag", task=task)
ti = TaskInstance(
id=uuid7(),
task_id=task.task_id,
dag_id=dag.dag_id,
run_id="test_run",
try_number=1,
dag_version_id=uuid7(),
)
runtime_ti = RuntimeTaskInstance.model_construct(
**ti.model_dump(exclude_unset=True), task=task, start_date=timezone.utcnow()
)
log = mock.MagicMock()
context = runtime_ti.get_template_context()
state, _, _ = run(runtime_ti, context, log)
finalize(runtime_ti, state, context, log)

log.exception.assert_any_call("error calling listener for hook %r", "on_task_instance_success")

@pytest.mark.parametrize(
"exception",
[
Expand Down
Loading