Skip to content

Conversation

@eaidova
Copy link

@eaidova eaidova commented Aug 23, 2024

add info about which cell executed in verbose logs, in some cases this info helpful for search source of Kernel Died error which does not have a lot of logs...

@amit1rrr
Copy link
Member

@eaidova Thank you for contributing to treon.

add info about which cell executed in verbose logs

I agree that this is useful. In addition to cell index, it would be better to log the cell content as well. E.g. if a user sees that cell #67 failed, there's no easy way (that I know of) in JupyterLab UI to go to cell #67. The user will have to manually start counting from the top. If they also see the cell content then they can cmd+F for it.

@eaidova
Copy link
Author

eaidova commented Aug 26, 2024

@amit1rrr I think your sggestion maybe too noisy... in case, if error happens there is stack trace with exact stacktrace including cell content. The problematic part for debugging is kernel died (that raised outside notebook and does not have any logging in some cases), so it will required to print every cell...

@amit1rrr
Copy link
Member

The problematic part for debugging is kernel died (that raised outside notebook and does not have any logging in some cases)

Can you please share an example notebook where this happens?

@eaidova
Copy link
Author

eaidova commented Aug 26, 2024

The problematic part for debugging is kernel died (that raised outside notebook and does not have any logging in some cases)

Can you please share an example notebook where this happens?

I was not able reproduce issue locally, only on ci machine, my treon logs looks like:

21:25:40  [2024-08-23 19:25:40,441] [14472] openvino_env-validate notebooks INFO: -----------------------------------------------------------------------
21:25:40  [2024-08-23 19:25:40,441] [14472] openvino_env-validate notebooks INFO: Collected following Notebooks for testing
21:25:40  [2024-08-23 19:25:40,441] [14472] openvino_env-validate notebooks INFO: -----------------------------------------------------------------------
21:25:40  [2024-08-23 19:25:40,441] [14472] openvino_env-validate notebooks INFO: test_yolov8-keypoint-detection.ipynb
21:25:40  [2024-08-23 19:25:40,441] [14472] openvino_env-validate notebooks INFO: -----------------------------------------------------------------------
21:25:40  [2024-08-23 19:25:40,441] [14472] openvino_env-validate notebooks INFO: 
21:25:40  [2024-08-23 19:25:40,446] [14472] openvino_env-validate notebooks INFO: Triggered test for test_yolov8-keypoint-detection.ipynb
21:25:41  [2024-08-23 19:25:40,746] [14472] openvino_env-validate notebooks INFO: c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\zmq\_future.py:724: RuntimeWarning: Proactor event loop does not implement add_reader family of methods required for zmq. Registering an additional selector thread for add_reader support via tornado. Use `asyncio.set_event_loop_policy(WindowsSelectorEventLoopPolicy())` to avoid this warning.
21:25:41  [2024-08-23 19:25:40,746] [14472] openvino_env-validate notebooks INFO:   self._get_loop()
21:25:53  [2024-08-23 19:25:53,629] [14472] openvino_env-validate notebooks INFO: Kernel died while waiting for execute reply.
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO: Traceback (most recent call last):
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:   File "C:\Program Files\Python310\lib\runpy.py", line 196, in _run_module_as_main
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:     return _run_code(code, main_globals, None,
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:   File "C:\Program Files\Python310\lib\runpy.py", line 86, in _run_code
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:     exec(code, run_globals)
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\treon\__main__.py", line 5, in <module>
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:     main()
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\treon\treon.py", line 52, in main
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:     trigger_tasks(tasks, thread_count)
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\treon\treon.py", line 71, in trigger_tasks
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:     pool.map(Task.run_tests, tasks)
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:   File "C:\Program Files\Python310\lib\multiprocessing\pool.py", line 367, in map
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:     return self._map_async(func, iterable, mapstar, chunksize).get()
21:25:53  [2024-08-23 19:25:53,633] [14472] openvino_env-validate notebooks INFO:   File "C:\Program Files\Python310\lib\multiprocessing\pool.py", line 774, in get
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     raise self._value
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "C:\Program Files\Python310\lib\multiprocessing\pool.py", line 125, in worker
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     result = (True, func(*args, **kwds))
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "C:\Program Files\Python310\lib\multiprocessing\pool.py", line 48, in mapstar
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     return list(map(*args))
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\treon\task.py", line 25, in run_tests
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     self.is_successful, console_output = execute_notebook(self.file_path, _is_verbose())
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\treon\test_execution.py", line 20, in execute_notebook
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     processor.preprocess(notebook, metadata(path))
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\nbconvert\preprocessors\execute.py", line 103, in preprocess
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     self.preprocess_cell(cell, resources, index)
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\nbconvert\preprocessors\execute.py", line 124, in preprocess_cell
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     cell = self.execute_cell(cell, index, store_history=True)
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\jupyter_core\utils\__init__.py", line 165, in wrapped
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     return loop.run_until_complete(inner)
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "C:\Program Files\Python310\lib\asyncio\base_events.py", line 646, in run_until_complete
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     return future.result()
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:   File "c:\jenkins\workspace\private-ci\nightlyJobs\notebooks-tests-windows\b\tmp\openvino_env\lib\site-packages\nbclient\client.py", line 1009, in async_execute_cell
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO:     raise DeadKernelError("Kernel died") from None
21:25:53  [2024-08-23 19:25:53,634] [14472] openvino_env-validate notebooks INFO: nbclient.exceptions.DeadKernelError: Kernel died

@amit1rrr
Copy link
Member

Thanks for sharing these.

Just FYI - I'm out of office for a week. I will review this as soon as I'm back.

@amit1rrr
Copy link
Member

amit1rrr commented Sep 8, 2024

Apologies for the delay.

The verbose logging should also list the file name since many of them are getting executed in parallel. So there would be no way to catch the culprit based on the current debug logging (see screenshot below). It should be something like -

Executing cell #1 for <file_path>

Screenshot 2024-09-08 at 6 02 49 PM

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants