Skip to content
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.

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

enable cell number print when verbose logging activates #26

Open
wants to merge 1 commit into
base: master
Choose a base branch
from

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