Add environment variable to log cudf.pandas fallback calls #16161
Conversation
mroeschke
added
improvement
python/cudf/cudf/pandas/_logger.py
Outdated
| @@ -0,0 +1,26 @@ | |||
| # SPDX-FileCopyrightText: Copyright (c) 2023-2024, NVIDIA CORPORATION & AFFILIATES. | |||
There was a problem hiding this comment.
| # SPDX-FileCopyrightText: Copyright (c) 2023-2024, NVIDIA CORPORATION & AFFILIATES. | |
| # SPDX-FileCopyrightText: Copyright (c) 2024, NVIDIA CORPORATION & AFFILIATES. |
There was a problem hiding this comment.
Thanks. A copy-paste oversight
| from ._logger import StructuredMessage, logger | ||
|
|
||
| def reprify(arg) -> str: | ||
| try: | ||
| return repr(arg) | ||
| except Exception: | ||
| return "<REPR FAILED>" | ||
|
|
||
| module = getattr(slow_args[0], "__module__", "") | ||
| obj_name = getattr( | ||
| slow_args[0], "__name__", type(slow_args[0]).__name__ | ||
| ) | ||
| slow_object = f"{module}.{obj_name}" | ||
| # TODO: maybe use inspect.signature to map called args and kwargs | ||
| # to their keyword names | ||
| called_args = ",".join((reprify(val) for val in slow_args[1])) | ||
| if len(slow_args) == 3: | ||
| fmt_kwargs = ",".join( | ||
| f"{kwarg}={reprify(value)}" | ||
| for kwarg, value in slow_args[2].items() | ||
| ) | ||
| called_args = ",".join((called_args, fmt_kwargs)) | ||
| passed_kwargs = { | ||
| kwarg: reprify(value) | ||
| for kwarg, value in slow_args[2].items() | ||
| } | ||
| else: | ||
| passed_kwargs = {} | ||
| message = StructuredMessage( | ||
| "CUDF_PANDAS_SLOW_LOG", | ||
| failed_call=f"{slow_object}({called_args})", | ||
| exception=type(err).__name__, | ||
| exception_message=str(err), | ||
| pandas_object=slow_object, | ||
| passed_args=called_args, | ||
| passed_kwargs=passed_kwargs, | ||
| ) | ||
| logger.info(message) |
There was a problem hiding this comment.
Can we pull all of this logic into the logger, so that we just do:
if should_log:
from ._logger import log_fallback
log_fallback(slow_args, slow_kwargs)
There was a problem hiding this comment.
Sure thing. Done.
| if len(slow_args) == 3: | ||
| fmt_kwargs = ",".join( | ||
| f"{kwarg}={reprify(value)}" | ||
| for kwarg, value in slow_args[2].items() | ||
| ) | ||
| called_args = ",".join((called_args, fmt_kwargs)) | ||
| passed_kwargs = { | ||
| kwarg: reprify(value) | ||
| for kwarg, value in slow_args[2].items() | ||
| } | ||
| else: | ||
| passed_kwargs = {} |
There was a problem hiding this comment.
Why are we never looking slow_kwargs?
There was a problem hiding this comment.
I think slow_kwargs is always empty. Because kwargs is getting subsumed by args in the _fast_slow_function_call calls. I opened #16266 to fix.
There was a problem hiding this comment.
I think slow_kwargs is always empty.
Correct. Seems like all calls to _fast_slow_function_call internally are of the form _fast_slow_function_call(something, object, args, kwargs) so kwargs are actually in slow_args instead of slow_kwargs
As commented in #16266 (comment) I am not sure this is exactly a bug
|
Just an fyi, I don't see the logs anywhere when I set the environment variable and run the pandas unit tests with |
The logs should show up in the cloned |
|
@wence- could I get a re-review when you have the time? |
|
/merge |
Description
Introduces a new environment variable
LOG_FAST_FALLBACKwhich will create a structured log of the call that failed.An example of the log is
I could turn this into a warning instead, but I imagine we would want to first utilize this to parse the failures and see generalized failures in aggregate
Checklist