Skip to content

[cards] debugging statements. #3273

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.

Sign up for GitHub

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

Open
valayDave wants to merge 1 commit into
base: master
Choose a base branch
from
+53 −0
Open

[cards] debugging statements. #3273

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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 metaflow/metaflow_config.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -540,6 +540,7 @@
"userconf",
"conda",
"package",
"card",
]

for typ in DEBUG_OPTIONS:
Expand Down
30 changes: 30 additions & 0 deletions metaflow/plugins/cards/card_creator.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
import sys
import os
from metaflow import current
from metaflow.debug import debug
from typing import Callable, Tuple, Dict


Expand Down Expand Up @@ -87,6 +88,10 @@ def create(
component_strings = current.card._serialize_components(card_uuid)
# Since the mode is a render, we can check if we need to write to the metadata store.
save_metadata, metadata_dict = self._should_save_metadata(card_uuid)
debug.card_exec(
"create card_uuid=%s mode=%s final=%s sync=%s runtime_card=%s save_metadata=%s"
% (card_uuid, mode, final, sync, runtime_card, save_metadata)
)
Comment on lines +91 to +94

@greptile-apps greptile-apps Bot Jun 15, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 Silent-ignore case not captured by debug log

When mode != "render" and not runtime_card the method returns early (line 82) before reaching this debug.card_exec call, so calls that are silently dropped are invisible even with debug enabled. Moving the debug statement before the if/elif/else block (or adding a separate log in the early-return branch) would make this case observable.

Note: If this suggestion doesn't match your team's coding style, reply to this and let me know. I'll remember it for next time!

data = current.card._get_latest_data(card_uuid, final=final, mode=mode)
runspec = "/".join([current.run_id, current.step_name, current.task_id])
self._run_cards_subprocess(
Expand Down Expand Up @@ -179,6 +184,7 @@ def _run_cards_subprocess(
if save_metadata:
cmd += ["--save-metadata", json.dumps(metadata_dict)]

debug.card_exec(cmd)
response, fail = self._run_command(
cmd,
card_uuid,
Expand Down Expand Up @@ -219,9 +225,28 @@ def _run_command(self, cmd, card_uuid, env, wait=True, timeout=None):
except subprocess.CalledProcessError as e:
rep = e.output
fail = True
if debug.card and rep is not None:
debug.card_exec(
"render subprocess for %s %s output:\n%s"
% (
card_uuid,
"FAILED" if fail else "succeeded",
rep.decode("utf-8"),
)
)
except subprocess.TimeoutExpired as e:
rep = e.output
fail = True
if debug.card and rep is not None:
debug.card_exec(
"render subprocess for %s %s output:\n%s"
% (
card_uuid,
"FAILED" if fail else "succeeded",
rep.decode("utf-8"),
)
)
Comment on lines 225 to +248

@greptile-apps greptile-apps Bot Jun 15, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 The "FAILED" if fail else "succeeded" conditional is dead code in both exception handlers — fail is set to True on the line immediately above, so the else branch can never execute. The suggestion also adds errors="replace" to rep.decode("utf-8") to avoid a UnicodeDecodeError if subprocess output contains non-UTF-8 bytes.

Suggested change
except subprocess.CalledProcessError as e:
rep = e.output
fail = True
if debug.card and rep is not None:
debug.card_exec(
"render subprocess for %s %s output:\n%s"
% (
card_uuid,
"FAILED" if fail else "succeeded",
rep.decode("utf-8"),
)
)
except subprocess.TimeoutExpired as e:
rep = e.output
fail = True
if debug.card and rep is not None:
debug.card_exec(
"render subprocess for %s %s output:\n%s"
% (
card_uuid,
"FAILED" if fail else "succeeded",
rep.decode("utf-8"),
)
)
except subprocess.CalledProcessError as e:
rep = e.output
fail = True
if debug.card and rep is not None:
debug.card_exec(
"render subprocess for %s FAILED output:\n%s"
% (
card_uuid,
rep.decode("utf-8", errors="replace"),
)
)
except subprocess.TimeoutExpired as e:
rep = e.output
fail = True
if debug.card and rep is not None:
debug.card_exec(
"render subprocess for %s TIMED OUT output:\n%s"
% (
card_uuid,
rep.decode("utf-8", errors="replace"),
)
)


return rep, fail
else:
_async_proc, _async_started = CardProcessManager._get_card_process(
Expand All @@ -238,8 +263,13 @@ def _run_command(self, cmd, card_uuid, env, wait=True, timeout=None):
else:
# silently refuse to run an async process if a previous one is still running
# and timeout hasn't been reached
debug.card_exec(
"skipping async render for %s: previous process still running"
% card_uuid
)
return "".encode(), False
else:
debug.card_exec("launching async render for %s" % card_uuid)
CardProcessManager._register_card_process(
card_uuid,
subprocess.Popen(
Expand Down
22 changes: 22 additions & 0 deletions metaflow/plugins/cards/card_decorator.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
from metaflow.user_configs.config_options import ConfigInput
from metaflow.user_configs.config_parameters import dump_config_values
from metaflow.util import to_unicode
from metaflow.debug import debug

from .component_serializer import CardComponentCollector, get_card_class
from .card_creator import CardCreator
Expand Down Expand Up @@ -241,6 +242,17 @@ def task_pre_step(
self._is_editable = True
self._is_runtime_card = card_class.RUNTIME_UPDATABLE

debug.card_exec(
"task_pre_step step=%s type=%s found=%s editable=%s runtime=%s"
% (
step_name,
card_type,
card_class is not None,
self._is_editable,
self._is_runtime_card,
)
)

# We have a step counter to ensure that on calling the final card decorator's `task_pre_step`
# we call a `finalize` function in the `CardComponentCollector`.
# This can help ensure the behaviour of the `current.card` object is according to specification.
Expand Down Expand Up @@ -322,6 +334,16 @@ def task_finished(
card_options=self.card_options,
logger=self._logger,
)
debug.card_exec(
"task_finished step=%s card_uuid=%s type=%s is_task_ok=%s -> %s"
% (
step_name,
self._card_uuid,
self.attributes["type"],
is_task_ok,
"rendering" if is_task_ok else "skipping (task failed)",
)
)
if is_task_ok:
self.card_creator.create(mode="render", final=True, **create_options)
self.card_creator.create(mode="refresh", final=True, **create_options)
Expand Down
Loading