So I'm debugging my python program and have encountered a bug that makes the program hang, as if in an infinite loop. Now, I had a problem with an infinite loop before, but when it hung up I could kill the program and python spat out a helpful exception that told me where the program terminated when I sent it the kill command. Now, however, when the program hangs up and I ctrl-c it, it does not abort but continues running. Is there any tool I can use to locate the hang up? I'm new to profiling but from what I know a profiler can only provide you with information about a program that has successfully completed. Or can you use a profiler to debug such hang ups?
14 Answers
From Python 3.3 on there is a built in faulthandler module. To print a stack trace for all the threads when a normally fatal signal occurs:
import faulthandler
faulthandler.enable()
For a process that is hung, it is more useful to setup faulthandler to print stack traces on demand. This can be done with:
import faulthandler
import signal
faulthandler.register(signal.SIGUSR1.value)
Then once the process becomes hung you can send a signal to trigger the printing of the stack trace:
$ python myscript.py &
[1] <pid>
$ kill -s SIGUSR1 <pid>
This signal won't kill the process, and you can send multiple times to see stack traces at different points in the execution.
Note that Python 3.5 or later is required for signal.SIGUSR1. For an older version, you can just hardcode the signal number (10 for most common linux architectures).
faulthandler.dump_traceback can be used together with threading.enumerate to identify threads having daemon=False to narrow down to hanging threads by their hex ID via hex(t.ident).
Multithreaded dæmon; using pyrasite to inspect a running program
I had a multithreaded dæmon that would sometimes get stuck after hours, sometimes after weeks. Running it through a debugger would be not feasible and perhaps not even helpful, as debugging multithreaded or multiprocess programs can be painful. Running it through trace might fill up gigabytes if not terabytes before it would get stuck. The second time the dæmon appeared to hang, I wanted to know right away where it was, without restarting it, adding inspection code, running it through a debugger, and waiting for hours, days, or weeks for it to hang again for circumstances yet to be investigated.
I was rescued by pyrasite, which lets the user connect to a running Python process and interactively inspect frames (example inspired by this gist):
$ pyrasite-shell 1071 # 1071 is the Process ID (PID)
Pyrasite Shell 2.0
Connected to '/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/bin/python3.8 /opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/bin/satpy_launcher.py -n localhost /opt/pytroll/pytroll_inst/config/trollflow2.yaml'
Python 3.8.6 | packaged by conda-forge | (default, Dec 26 2020, 05:05:16)
[GCC 9.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
(DistantInteractiveConsole)
>>> import sys
>>> sys._current_frames()
{139652793759488: <frame at 0x7f034b2c9040, file '<console>', line 1, code <module>>, 139653520578368: <frame at 0x7f034b232ac0, file '/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py', line 112, code __init__>}
The first frame is not informative; that's our own pyrasite shell. The second frame, however, reveals that currently our script is stuck in the module pyresample.spherical in line 112. We can use the traceback module to get a full traceback:
>>> import traceback
>>> traceback.print_stack(list(sys._current_frames().values())[1])
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/bin/satpy_launcher.py", line 80, in <module>
main()
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/bin/satpy_launcher.py", line 75, in main
run(prod_list, topics=topics, test_message=test_message,
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/trollflow2/launcher.py", line 152, in run
proc.start()
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/multiprocessing/process.py", line 121, in start
self._popen = self._Popen(self)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/multiprocessing/context.py", line 224, in _Popen
return _default_context.get_context().Process._Popen(process_obj)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/multiprocessing/context.py", line 277, in _Popen
return Popen(process_obj)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/multiprocessing/popen_fork.py", line 19, in __init__
self._launch(process_obj)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/multiprocessing/popen_fork.py", line 75, in _launch
code = process_obj._bootstrap(parent_sentinel=child_r)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
self.run()
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/multiprocessing/process.py", line 108, in run
self._target(*self._args, **self._kwargs)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/trollflow2/launcher.py", line 268, in process
cwrk.pop('fun')(job, **cwrk)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/trollflow2/plugins/__init__.py", line 403, in covers
cov = get_scene_coverage(platform_name, start_time, end_time,
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/trollflow2/plugins/__init__.py", line 425, in get_scene_coverage
return 100 * overpass.area_coverage(area_def)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/trollsched/satpass.py", line 242, in area_coverage
inter = self.boundary.contour_poly.intersection(area_boundary)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py", line 494, in intersection
return self._bool_oper(other, -1)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py", line 475, in _bool_oper
inter, edge2 = edge1.get_next_intersection(narcs2, inter)
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py", line 326, in get_next_intersection
return None, None
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py", line 298, in intersection
return None
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py", line 264, in intersections
return (SCoordinate(lon, lat),
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py", line 62, in cross2cart
return res
File "/opt/pytroll/pytroll_inst/miniconda3/envs/pytroll-py38/lib/python3.8/site-packages/pyresample/spherical.py", line 112, in __init__
self.cart = np.array(cart)
and we can use all the power of Pythons introspection to inspect the stack in order to help us reconstruct the circumstances where this got stuck.
Related