Better Error Logging #3651

lordsoffallen · 2024-02-25T16:05:35Z

Description

Usually when my code errors out, the stack trace is quite long and half of them coming from kedro. So far, kedro stack trace isn't really helping when it comes to debugging as issues are on my code. It would be quite nice if we can disable kedro stack trace so when something errors out regarding user code, i.e executing the node function, then only shown where the code fails.

Context

Possible Implementation

Possible Alternatives

noklam · 2024-02-25T22:49:32Z

@lordsoffallen Can you show an example and explain what would you preferred to see instead? And please include the version of Kedro

lordsoffallen · 2024-02-26T11:06:11Z

Sure, this is what I get now (created a dummy error function).

[02/26/24 12:04:26] INFO     Kedro project huggingface-finder                                                       session.py:321
[02/26/24 12:04:27] INFO     Using synchronous mode for loading and saving data. Use the --async flag for  sequential_runner.py:64
                             potential performance gains.                                                                         
                             https://docs.kedro.org/en/stable/nodes_and_pipelines/run_a_pipeline.html#load                        
                             -and-save-asynchronously                                                                             
                    INFO     Loading data from clean_model#hf (HFDataset)...                                   data_catalog.py:483
                    INFO     Running node: tmp: myfunction([clean_model#hf]) -> None                                   node.py:340
                    ERROR    Node tmp: myfunction() -> None failed with error:                                         node.py:365
                                                                                                                                  
                    WARNING  No nodes ran. Repeat the previous command to attempt a new run.                         runner.py:214
╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /home/ftopal/miniconda3/envs/huggingface-finder/bin/kedro:10 in <module>                         │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/framework/cli │
│ /cli.py:198 in main                                                                              │
│                                                                                                  │
│   195 │   """                                                                                    │
│   196 │   _init_plugins()                                                                        │
│   197 │   cli_collection = KedroCLI(project_path=Path.cwd())                                     │
│ ❱ 198 │   cli_collection()                                                                       │
│   199                                                                                            │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/click/core.py:1157  │
│ in __call__                                                                                      │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/framework/cli │
│ /cli.py:127 in main                                                                              │
│                                                                                                  │
│   124 │   │   )                                                                                  │
│   125 │   │                                                                                      │
│   126 │   │   try:                                                                               │
│ ❱ 127 │   │   │   super().main(                                                                  │
│   128 │   │   │   │   args=args,                                                                 │
│   129 │   │   │   │   prog_name=prog_name,                                                       │
│   130 │   │   │   │   complete_var=complete_var,                                                 │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/click/core.py:1078  │
│ in main                                                                                          │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/click/core.py:1688  │
│ in invoke                                                                                        │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/click/core.py:1434  │
│ in invoke                                                                                        │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/click/core.py:783   │
│ in invoke                                                                                        │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/framework/cli │
│ /project.py:225 in run                                                                           │
│                                                                                                  │
│   222 │   with KedroSession.create(                                                              │
│   223 │   │   env=env, conf_source=conf_source, extra_params=params                              │
│   224 │   ) as session:                                                                          │
│ ❱ 225 │   │   session.run(                                                                       │
│   226 │   │   │   tags=tuple_tags,                                                               │
│   227 │   │   │   runner=runner_obj(is_async=is_async),                                          │
│   228 │   │   │   node_names=tuple_node_names,                                                   │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/framework/ses │
│ sion/session.py:392 in run                                                                       │
│                                                                                                  │
│   389 │   │   )                                                                                  │
│   390 │   │                                                                                      │
│   391 │   │   try:                                                                               │
│ ❱ 392 │   │   │   run_result = runner.run(                                                       │
│   393 │   │   │   │   filtered_pipeline, catalog, hook_manager, session_id                       │
│   394 │   │   │   )                                                                              │
│   395 │   │   │   self._run_called = True                                                        │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/runner/runner │
│ .py:117 in run                                                                                   │
│                                                                                                  │
│   114 │   │   │   self._logger.info(                                                             │
│   115 │   │   │   │   "Asynchronous mode is enabled for loading and saving data"                 │
│   116 │   │   │   )                                                                              │
│ ❱ 117 │   │   self._run(pipeline, catalog, hook_or_null_manager, session_id)  # type: ignore[a   │
│   118 │   │                                                                                      │
│   119 │   │   self._logger.info("Pipeline execution completed successfully.")                    │
│   120                                                                                            │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/runner/sequen │
│ tial_runner.py:75 in _run                                                                        │
│                                                                                                  │
│   72 │   │                                                                                       │
│   73 │   │   for exec_index, node in enumerate(nodes):                                           │
│   74 │   │   │   try:                                                                            │
│ ❱ 75 │   │   │   │   run_node(node, catalog, hook_manager, self._is_async, session_id)           │
│   76 │   │   │   │   done_nodes.add(node)                                                        │
│   77 │   │   │   except Exception:                                                               │
│   78 │   │   │   │   self._suggest_resume_scenario(pipeline, done_nodes, catalog)                │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/runner/runner │
│ .py:331 in run_node                                                                              │
│                                                                                                  │
│   328 │   if is_async:                                                                           │
│   329 │   │   node = _run_node_async(node, catalog, hook_manager, session_id)                    │
│   330 │   else:                                                                                  │
│ ❱ 331 │   │   node = _run_node_sequential(node, catalog, hook_manager, session_id)               │
│   332 │                                                                                          │
│   333 │   for name in node.confirms:                                                             │
│   334 │   │   catalog.confirm(name)                                                              │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/runner/runner │
│ .py:424 in _run_node_sequential                                                                  │
│                                                                                                  │
│   421 │   )                                                                                      │
│   422 │   inputs.update(additional_inputs)                                                       │
│   423 │                                                                                          │
│ ❱ 424 │   outputs = _call_node_run(                                                              │
│   425 │   │   node, catalog, inputs, is_async, hook_manager, session_id=session_id               │
│   426 │   )                                                                                      │
│   427                                                                                            │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/runner/runner │
│ .py:390 in _call_node_run                                                                        │
│                                                                                                  │
│   387 │   │   │   is_async=is_async,                                                             │
│   388 │   │   │   session_id=session_id,                                                         │
│   389 │   │   )                                                                                  │
│ ❱ 390 │   │   raise exc                                                                          │
│   391 │   hook_manager.hook.after_node_run(                                                      │
│   392 │   │   node=node,                                                                         │
│   393 │   │   catalog=catalog,                                                                   │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/runner/runner │
│ .py:380 in _call_node_run                                                                        │
│                                                                                                  │
│   377 │   session_id: str | None = None,                                                         │
│   378 ) -> dict[str, Any]:                                                                       │
│   379 │   try:                                                                                   │
│ ❱ 380 │   │   outputs = node.run(inputs)                                                         │
│   381 │   except Exception as exc:                                                               │
│   382 │   │   hook_manager.hook.on_node_error(                                                   │
│   383 │   │   │   error=exc,                                                                     │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/pipeline/node │
│ .py:371 in run                                                                                   │
│                                                                                                  │
│   368 │   │   │   │   str(exc),                                                                  │
│   369 │   │   │   │   extra={"markup": True},                                                    │
│   370 │   │   │   )                                                                              │
│ ❱ 371 │   │   │   raise exc                                                                      │
│   372 │                                                                                          │
│   373 │   def _run_with_no_inputs(self, inputs: dict[str, Any]) -> Any:                          │
│   374 │   │   if inputs:                                                                         │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/pipeline/node │
│ .py:355 in run                                                                                   │
│                                                                                                  │
│   352 │   │   │   if not self._inputs:                                                           │
│   353 │   │   │   │   outputs = self._run_with_no_inputs(inputs)                                 │
│   354 │   │   │   elif isinstance(self._inputs, str):                                            │
│ ❱ 355 │   │   │   │   outputs = self._run_with_one_input(inputs, self._inputs)                   │
│   356 │   │   │   elif isinstance(self._inputs, list):                                           │
│   357 │   │   │   │   outputs = self._run_with_list(inputs, self._inputs)                        │
│   358 │   │   │   elif isinstance(self._inputs, dict):                                           │
│                                                                                                  │
│ /home/ftopal/miniconda3/envs/huggingface-finder/lib/python3.10/site-packages/kedro/pipeline/node │
│ .py:391 in _run_with_one_input                                                                   │
│                                                                                                  │
│   388 │   │   │   │   f"{sorted(inputs.keys())}."                                                │
│   389 │   │   │   )                                                                              │
│   390 │   │                                                                                      │
│ ❱ 391 │   │   return self._func(inputs[node_input])                                              │
│   392 │                                                                                          │
│   393 │   def _run_with_list(self, inputs: dict[str, Any], node_inputs: list[str]) -> Any:       │
│   394 │   │   # Node inputs and provided run inputs should completely overlap                    │
│                                                                                                  │
│ /home/ftopal/Projects/huggingface-finder/src/hffinder/pipelines/data.py:207 in myfunction        │
│                                                                                                  │
│   204                                                                                            │
│   205                                                                                            │
│   206 def myfunction(d):                                                                         │
│ ❱ 207 │   dummy_error()                                                                          │
│   208                                                                                            │
│                                                                                                  │
│ /home/ftopal/Projects/huggingface-finder/src/hffinder/pipelines/data.py:203 in dummy_error       │
│                                                                                                  │
│   200                                                                                            │
│   201                                                                                            │
│   202 def dummy_error():                                                                         │
│ ❱ 203 │   raise ValueError                                                                       │
│   204                                                                                            │
│   205                                                                                            │
│   206 def myfunction(d):                                                                         │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
ValueError

lordsoffallen · 2024-02-26T11:09:00Z

What I would like to have: (couple of more from kedro at the beginning would be okay.)

[02/26/24 12:04:26] INFO     Kedro project huggingface-finder                                                       session.py:321
[02/26/24 12:04:27] INFO     Using synchronous mode for loading and saving data. Use the --async flag for  sequential_runner.py:64
                             potential performance gains.                                                                         
                             https://docs.kedro.org/en/stable/nodes_and_pipelines/run_a_pipeline.html#load                        
                             -and-save-asynchronously                                                                             
                    INFO     Loading data from clean_model#hf (HFDataset)...                                   data_catalog.py:483
                    INFO     Running node: tmp: myfunction([clean_model#hf]) -> None                                   node.py:340
                    ERROR    Node tmp: myfunction() -> None failed with error:                                         node.py:365
                                                                                                                                  
                    WARNING  No nodes ran. Repeat the previous command to attempt a new run.                         runner.py:214
╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /home/ftopal/Projects/huggingface-finder/src/hffinder/pipelines/data.py:207 in myfunction        │
│                                                                                                  │
│   204                                                                                            │
│   205                                                                                            │
│   206 def myfunction(d):                                                                         │
│ ❱ 207 │   dummy_error()                                                                          │
│   208                                                                                            │
│                                                                                                  │
│ /home/ftopal/Projects/huggingface-finder/src/hffinder/pipelines/data.py:203 in dummy_error       │
│                                                                                                  │
│   200                                                                                            │
│   201                                                                                            │
│   202 def dummy_error():                                                                         │
│ ❱ 203 │   raise ValueError                                                                       │
│   204                                                                                            │
│   205                                                                                            │
│   206 def myfunction(d):                                                                         │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
ValueError

lordsoffallen · 2024-02-26T11:12:13Z

@noklam Basically, a possible option to turn off kedro stacktrace when an error happens. Now I have to scroll up to find when an error occured. It would be really nice to have simpler logging in this case. I was gonna try something with on_node_error hook but I am not sure how that plays our with rich logger as I like it on my terminal.

noklam · 2024-02-26T12:40:29Z

For reference, this is the log I see in 0.19.2.

Current log

(

kedro) Nok_Lam_Chan@ debug-kedro % kedro run
[02/26/24 12:38:34] INFO Kedro project debug-kedro session.py:321
Setting default log level to "WARN".
To adjust logging level use sc.setLogLevel(newLevel). For SparkR, use setLogLevel(newLevel).
24/02/26 12:38:35 WARN NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
[02/26/24 12:38:36] INFO Reached after_catalog_created hook plugin.py:15
INFO Using synchronous mode for loading and saving data. Use the --async sequential_runner.py:64
flag for potential performance gains.
https://docs.kedro.org/en/stable/nodes_and_pipelines/run_a_pipeline.
html#load-and-save-asynchronously
INFO Loading data from companies (SparkDataset)... data_catalog.py:483
[02/26/24 12:38:39] INFO Running node: create_confusion_matrix([companies]) -> [dummy_confusion_matrix] node.py:340
INFO Saving data to dummy_confusion_matrix (MatplotlibWriter)... data_catalog.py:525
INFO Completed 1 out of 11 tasks sequential_runner.py:90
INFO Loading data from shuttles@excel (ExcelDataset)... data_catalog.py:483
[02/26/24 12:38:40] INFO Running node: load_shuttles_to_csv_node: load_shuttles_to_csv([shuttles@excel]) node.py:340
-> [shuttles@csv]
INFO Saving data to shuttles@csv (CSVDataset)... data_catalog.py:525
INFO Completed 2 out of 11 tasks sequential_runner.py:90
INFO Loading data from companies (SparkDataset)... data_catalog.py:483
INFO Running node: preprocess_companies_node: preprocess_companies([companies]) -> node.py:340
[preprocessed_companies;companies_columns]
INFO Saving data to preprocessed_companies (SparkDataset)... data_catalog.py:525
[02/26/24 12:38:41] INFO Saving data to companies_columns (JSONDataset)... data_catalog.py:525
INFO Completed 3 out of 11 tasks sequential_runner.py:90
INFO Loading data from reviews (SparkDataset)... data_catalog.py:483
INFO Running node: preprocess_reviews_node: preprocess_reviews([reviews]) -> node.py:340
[preprocessed_reviews]
INFO Saving data to preprocessed_reviews (SparkDataset)... data_catalog.py:525
INFO Completed 4 out of 11 tasks sequential_runner.py:90
INFO Loading data from shuttles@spark (SparkDataset)... data_catalog.py:483
INFO Running node: preprocess_shuttles_node: preprocess_shuttles([shuttles@spark]) -> node.py:340
[preprocessed_shuttles]
ERROR Node preprocess_shuttles_node: preprocess_shuttles() -> failed with error: node.py:365
                WARNING  There are 7 nodes that have not run.                                           runner.py:218
                         You can resume the pipeline run from the nearest nodes with persisted inputs                
                         by adding the following argument to your previous command:                                  
                           --from-nodes "preprocess_shuttles_node,create_model_input_table_node"                     
╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/bin/kedro:8 in │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/framework/cli/cli.p │
│ y:198 in main │
│ │
│ 195 │ """ │
│ 196 │ _init_plugins() │
│ 197 │ cli_collection = KedroCLI(project_path=Path.cwd()) │
│ ❱ 198 │ cli_collection() │
│ 199 │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1157 in │
│ call │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/framework/cli/cli.p │
│ y:127 in main │
│ │
│ 124 │ │ ) │
│ 125 │ │ │
│ 126 │ │ try: │
│ ❱ 127 │ │ │ super().main( │
│ 128 │ │ │ │ args=args, │
│ 129 │ │ │ │ prog_name=prog_name, │
│ 130 │ │ │ │ complete_var=complete_var, │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1078 in │
│ main │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1688 in │
│ invoke │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1434 in │
│ invoke │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:783 in │
│ invoke │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/framework/cli/proje │
│ ct.py:225 in run │
│ │
│ 222 │ with KedroSession.create( │
│ 223 │ │ env=env, conf_source=conf_source, extra_params=params │
│ 224 │ ) as session: │
│ ❱ 225 │ │ session.run( │
│ 226 │ │ │ tags=tuple_tags, │
│ 227 │ │ │ runner=runner_obj(is_async=is_async), │
│ 228 │ │ │ node_names=tuple_node_names, │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/framework/session/s │
│ ession.py:392 in run │
│ │
│ 389 │ │ ) │
│ 390 │ │ │
│ 391 │ │ try: │
│ ❱ 392 │ │ │ run_result = runner.run( │
│ 393 │ │ │ │ filtered_pipeline, catalog, hook_manager, session_id │
│ 394 │ │ │ ) │
│ 395 │ │ │ self._run_called = True │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/runner/runner.py:11 │
│ 7 in run │
│ │
│ 114 │ │ │ self._logger.info( │
│ 115 │ │ │ │ "Asynchronous mode is enabled for loading and saving data" │
│ 116 │ │ │ ) │
│ ❱ 117 │ │ self._run(pipeline, catalog, hook_or_null_manager, session_id) # type: ignore[a │
│ 118 │ │ │
│ 119 │ │ self._logger.info("Pipeline execution completed successfully.") │
│ 120 │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/runner/sequential_r │
│ unner.py:75 in _run │
│ │
│ 72 │ │ │
│ 73 │ │ for exec_index, node in enumerate(nodes): │
│ 74 │ │ │ try: │
│ ❱ 75 │ │ │ │ run_node(node, catalog, hook_manager, self._is_async, session_id) │
│ 76 │ │ │ │ done_nodes.add(node) │
│ 77 │ │ │ except Exception: │
│ 78 │ │ │ │ self._suggest_resume_scenario(pipeline, done_nodes, catalog) │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/runner/runner.py:33 │
│ 1 in run_node │
│ │
│ 328 │ if is_async: │
│ 329 │ │ node = _run_node_async(node, catalog, hook_manager, session_id) │
│ 330 │ else: │
│ ❱ 331 │ │ node = _run_node_sequential(node, catalog, hook_manager, session_id) │
│ 332 │ │
│ 333 │ for name in node.confirms: │
│ 334 │ │ catalog.confirm(name) │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/runner/runner.py:42 │
│ 4 in _run_node_sequential │
│ │
│ 421 │ ) │
│ 422 │ inputs.update(additional_inputs) │
│ 423 │ │
│ ❱ 424 │ outputs = _call_node_run( │
│ 425 │ │ node, catalog, inputs, is_async, hook_manager, session_id=session_id │
│ 426 │ ) │
│ 427 │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/runner/runner.py:39 │
│ 0 in _call_node_run │
│ │
│ 387 │ │ │ is_async=is_async, │
│ 388 │ │ │ session_id=session_id, │
│ 389 │ │ ) │
│ ❱ 390 │ │ raise exc │
│ 391 │ hook_manager.hook.after_node_run( │
│ 392 │ │ node=node, │
│ 393 │ │ catalog=catalog, │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/runner/runner.py:38 │
│ 0 in _call_node_run │
│ │
│ 377 │ session_id: str | None = None, │
│ 378 ) -> dict[str, Any]: │
│ 379 │ try: │
│ ❱ 380 │ │ outputs = node.run(inputs) │
│ 381 │ except Exception as exc: │
│ 382 │ │ hook_manager.hook.on_node_error( │
│ 383 │ │ │ error=exc, │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/pipeline/node.py:37 │
│ 1 in run │
│ │
│ 368 │ │ │ │ str(exc), │
│ 369 │ │ │ │ extra={"markup": True}, │
│ 370 │ │ │ ) │
│ ❱ 371 │ │ │ raise exc │
│ 372 │ │
│ 373 │ def _run_with_no_inputs(self, inputs: dict[str, Any]) -> Any: │
│ 374 │ │ if inputs: │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/pipeline/node.py:35 │
│ 5 in run │
│ │
│ 352 │ │ │ if not self._inputs: │
│ 353 │ │ │ │ outputs = self._run_with_no_inputs(inputs) │
│ 354 │ │ │ elif isinstance(self._inputs, str): │
│ ❱ 355 │ │ │ │ outputs = self._run_with_one_input(inputs, self._inputs) │
│ 356 │ │ │ elif isinstance(self._inputs, list): │
│ 357 │ │ │ │ outputs = self._run_with_list(inputs, self._inputs) │
│ 358 │ │ │ elif isinstance(self._inputs, dict): │
│ │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/kedro/pipeline/node.py:39 │
│ 1 in _run_with_one_input │
│ │
│ 388 │ │ │ │ f"{sorted(inputs.keys())}." │
│ 389 │ │ │ ) │
│ 390 │ │ │
│ ❱ 391 │ │ return self._func(inputs[node_input]) │
│ 392 │ │
│ 393 │ def _run_with_list(self, inputs: dict[str, Any], node_inputs: list[str]) -> Any: │
│ 394 │ │ # Node inputs and provided run inputs should completely overlap │
│ │
│ /Users/Nok_Lam_Chan/dev/kedro/tmp/debug-kedro/src/debug_kedro/pipelines/data_processing/nodes.py │
│ :73 in preprocess_shuttles │
│ │
│ 70 │ """ │
│ 71 │ shuttles = shuttles.withColumn("d_check_complete", _is_true(shuttles.d_check_complet │
│ 72 │ shuttles = shuttles.withColumn("moon_clearance_complete", _is_true(shuttles.moon_cle │
│ ❱ 73 │ shuttles = shuttles.withColumn("price", _parse_money(shuttles.price)) │
│ 74 │ │
│ 75 │ # Drop columns that aren't used for model training │
│ 76 │ shuttles = shuttles.drop('shuttle_location', 'engine_type', 'engine_vendor', 'cancel │
│ │
│ /Users/Nok_Lam_Chan/dev/kedro/tmp/debug-kedro/src/debug_kedro/pipelines/data_processing/nodes.py │
│ :21 in _parse_money │
│ │
│ 18 │
│ 19 │
│ 20 def _parse_money(x: Column) -> Column: │
│ ❱ 21 │ raise ValueError │
│ 22 │ x = regexp_replace(x, "[$£€]", "") │
│ 23 │ x = regexp_replace(x, ",", "") │
│ 24 │ x = x.cast(DoubleType()) │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯

If I try to suppress kedro's log, the result is this

╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/bin/kedro:8 in <module>                                │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/framework/cli/cli.py:198 in main                             │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1157 in     │
│ __call__                                                                                         │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/framework/cli/cli.py:127 in main                             │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1078 in     │
│ main                                                                                             │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1688 in     │
│ invoke                                                                                           │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:1434 in     │
│ invoke                                                                                           │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/miniconda3/envs/kedro/lib/python3.10/site-packages/click/core.py:783 in      │
│ invoke                                                                                           │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/framework/cli/project.py:225 in run                          │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/framework/session/session.py:392 in run                      │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/runner/runner.py:117 in run                                  │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/runner/sequential_runner.py:75 in _run                       │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/runner/runner.py:331 in run_node                             │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/runner/runner.py:424 in _run_node_sequential                 │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/runner/runner.py:390 in _call_node_run                       │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/runner/runner.py:380 in _call_node_run                       │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/pipeline/node.py:371 in run                                  │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/pipeline/node.py:355 in run                                  │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/kedro/pipeline/node.py:391 in _run_with_one_input                  │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/tmp/debug-kedro/src/debug_kedro/pipelines/data_processing/nodes.py │
│ :73 in preprocess_shuttles                                                                       │
│                                                                                                  │
│    70 │   """                                                                                    │
│    71 │   shuttles = shuttles.withColumn("d_check_complete", _is_true(shuttles.d_check_complet   │
│    72 │   shuttles = shuttles.withColumn("moon_clearance_complete", _is_true(shuttles.moon_cle   │
│ ❱  73 │   shuttles = shuttles.withColumn("price", _parse_money(shuttles.price))                  │
│    74 │                                                                                          │
│    75 │   # Drop columns that aren't used for model training                                     │
│    76 │   shuttles = shuttles.drop('shuttle_location', 'engine_type', 'engine_vendor', 'cancel   │
│                                                                                                  │
│ /Users/Nok_Lam_Chan/dev/kedro/tmp/debug-kedro/src/debug_kedro/pipelines/data_processing/nodes.py │
│ :21 in _parse_money                                                                              │
│                                                                                                  │
│    18                                                                                            │
│    19                                                                                            │
│    20 def _parse_money(x: Column) -> Column:                                                     │
│ ❱  21 │   raise ValueError                                                                       │
│    22 │   x = regexp_replace(x, "[$£€]", "")                                                     │
│    23 │   x = regexp_replace(x, ",", "")                                                         │
│    24 │   x = x.cast(DoubleType())                                                               │
╰───────────────────────────────────────

The change is adding kedro into this line. What do you think? This need to be think carefully because it may suppress too much for other cases.

kedro/kedro/logging.py

Line 43 in 527108c

"suppress": [click, str(Path(sys.executable).parent)]

lordsoffallen · 2024-02-26T18:46:17Z

This is already an improvement to me. Completly surpassing may not help if a user had kedro related errors in the code. An option in the logging file to enable this would be super useful.

If we can do something like the following that would be best case I suppose:

If the stack trace involves user code, potentially issue is use related so turn off kedro logs
if stack trace didn't reach to user code something within kedro failed so show whole stack trace.

I might be missing some cases but that's what I have in mind. Even a easy option to suppress this would be cool. (I don't know if this can be done on user side or not)

noklam · 2024-02-27T09:24:56Z

@lordsoffallen Technically you can already do that.

Here is an example of logging.

The optional argument can be configure via logging.yml, which has to comply with what logging.dictConfig accept. So it should be possible to override via a key suppress under the rich handler. The problem is it expect a path, not a name of the library.

kedro/kedro/logging.py

Lines 42 to 60 in 527108c

    
           traceback_install_kwargs = { 
        
               "suppress": [click, str(Path(sys.executable).parent)] 
        
           } 
        
           # Mapping arguments from RichHandler's Constructor to rich.traceback.install 
        
           prefix = "tracebacks_" 
        
           for key, value in kwargs.items(): 
        
               if key.startswith(prefix): 
        
                   key_prefix_removed = key[len(prefix) :] 
        
                   if key_prefix_removed == "suppress": 
        
                       traceback_install_kwargs[key_prefix_removed].extend(value) 
        
                   else: 
        
                       traceback_install_kwargs[key_prefix_removed] = value 
        
           if self.rich_tracebacks and not _is_databricks(): 
        
               # Rich traceback handling does not work on databricks. Hopefully this will be 
        
               # fixed on their side at some point, but until then we disable it. 
        
               # See https://github.com/Textualize/rich/issues/2455 
        
               rich.traceback.install(**traceback_install_kwargs)  # type: ignore[arg-type]

If we can do something like the following that would be best case I suppose:

If the stack trace involves user code, potentially issue is use related so turn off kedro logs
if stack trace didn't reach to user code something within kedro failed so show whole stack trace.
Are you interested to raise a PR to experiment how it could work?

lordsoffallen · 2024-02-27T12:05:39Z

Thanks for the link.

Is the logging,yml file have no affect without the KEDRO_LOGGING_CONFIG? I didn't know about this, i created a project and this filed existed so I assumed this was the config that was used, I feel like it's a different to have this file but end up using a default file which is not visible to user?
If I create a RichHandler class and mock kedro and then pass this into

  rich:
    class:  MY CUSTOM RichHandler
    rich_tracebacks: True

then it should work as I expect ?

Regarding the PR, I don't have much experience with logging nor rich library so not sure how much I can contribute here but if I find something that works I'd be happy to share this here somehow.

noklam · 2024-03-01T11:30:56Z

@lordsoffallen

Is the logging,yml file have no affect without the KEDRO_LOGGING_CONFIG? I didn't know about this, i created a project and this filed existed so I assumed this was the config that was used, I feel like it's a different to have this file but end up using a default file which is not visible to user?

With 0.19, this is true that logging.yml is no longer pick up automatically. There is a reason why we need to use environment variable and de-couple it from ConfigLoader. Personally I don't really like this, and may even consider this as a bug because in kedro new we allow user to choose log but this actually has no effect until you activate it with env var.

This is why I proposed #3446 to change this.

For your second question, you cannot mock Kedro because you need Kedro to run your pipeline. You can create a custom rich handler, change the "suppressed" settings and register it in logging.yml to use this rich handler over the Kedro one.

Regarding the PR, I don't have much experience with logging nor rich library so not sure how much I can contribute here but if I find something that works I'd be happy to share this here somehow.

This is fine! If you can comment on the relevant issues and share your insight, it would already helped us prioritise and design a generic solution a lot.

lordsoffallen added the Issue: Feature Request New feature or improvement to existing feature label Feb 25, 2024

noklam added this to the Something about logging milestone Feb 26, 2024

github-actions bot mentioned this issue Mar 1, 2024

Monthly issue metrics report #3671

Open

noklam mentioned this issue Mar 1, 2024

[Draft] - Improve the Kedro Run log, make "go to definition" easier #3672

Open

noklam mentioned this issue Mar 7, 2024

Kedro tracebacks are overwhelming #2401

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Better Error Logging #3651

Better Error Logging #3651

lordsoffallen commented Feb 25, 2024

noklam commented Feb 25, 2024

lordsoffallen commented Feb 26, 2024

lordsoffallen commented Feb 26, 2024

lordsoffallen commented Feb 26, 2024

noklam commented Feb 26, 2024 •

edited

Loading

lordsoffallen commented Feb 26, 2024

noklam commented Feb 27, 2024

lordsoffallen commented Feb 27, 2024

noklam commented Mar 1, 2024

Better Error Logging #3651

Better Error Logging #3651

Comments

lordsoffallen commented Feb 25, 2024

Description

Context

Possible Implementation

Possible Alternatives

noklam commented Feb 25, 2024

lordsoffallen commented Feb 26, 2024

lordsoffallen commented Feb 26, 2024

lordsoffallen commented Feb 26, 2024

noklam commented Feb 26, 2024 • edited Loading

lordsoffallen commented Feb 26, 2024

noklam commented Feb 27, 2024

lordsoffallen commented Feb 27, 2024

noklam commented Mar 1, 2024

noklam commented Feb 26, 2024 •

edited

Loading