Симптомы. Один из подпроцессов в поде кубернетса просто вис и не логировал данные.
Заходим в поду.
Чтобы понять про процессы:
$ top
top - 19:00:06 up 22 days, 10:42, 0 users, load average: 0.79, 0.89, 1.11
Tasks: 13 total, 1 running, 7 sleeping, 0 stopped, 5 zombie
%Cpu(s): 1.2 us, 1.4 sy, 0.0 ni, 95.0 id, 2.1 wa, 0.2 hi, 0.1 si, 0.1 st
MiB Mem : 32165.3 total, 14305.0 free, 3202.7 used, 14657.6 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 28626.0 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
9 root 20 0 167064 73724 8364 S 3.0 0.2 141:45.52 python
1 root 20 0 381020 53148 13248 S 0.0 0.2 26:46.39 python
780 root 20 0 381020 43252 3324 S 0.0 0.1 0:00.00 python
781 root 20 0 381020 43224 3304 S 0.0 0.1 0:00.00 python
4498 root 20 0 5756 3656 3120 S 0.0 0.0 0:00.07 bash
4544 root 20 0 0 0 0 Z 0.0 0.0 0:00.04 python
4986 root 20 0 381020 43220 3300 S 0.0 0.1 0:00.00 python
Есть несколько процессов Питона. Надо понять какой соотвествует зависшему. Обычно если зависло, то упёрлось в логику бесконечного цикла или в системный вызов. Скорее всего искать надо среди тех что cpu=0.0, но для иллюстрации покажу и другой пример.
Сначала проверяем системный вызов. Я попробовал для этого трассировщик системных вызовов strace.
Взял один процесс c pid=9
$ strace -p 9
strace: Process 9 attached
select(0, NULL, NULL, NULL, {tv_sec=1, tv_usec=22746}) = 0 (Timeout)
getpid() = 9
write(2, "2020-03-04 19:10:43,932 nlab.arm"..., 80) = 80
sendto(5, "Q\0\0\1\235SELECT tasks.task_id AS tas"..., 414, MSG_NOSIGNAL, NULL, 0) = 414
poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "T\0\0\1<\0\ntasks_task_id\0\0\3\4\271\0\1\0\0\v\206\0"..., 16384, 0, NULL, NULL) = 337
select(0, NULL, NULL, NULL, {tv_sec=2, tv_usec=0}) = 0 (Timeout)
getpid() = 9
write(2, "2020-03-04 19:10:45,940 nlab.arm"..., 80) = 80
sendto(5, "Q\0\0\1\235SELECT tasks.task_id AS tas"..., 414, MSG_NOSIGNAL, NULL, 0) = 414
poll([{fd=5, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])
recvfrom(5, "T\0\0\1<\0\ntasks_task_id\0\0\3\4\271\0\1\0\0\v\206\0"..., 16384, 0, NULL, NULL) = 337
select(0, NULL, NULL, NULL, {tv_sec=2, tv_usec=0}^Cstrace: Process 9 detached
<detached ...>
Ну тут идут какие-то запросы. Берём дальше pid=780.
$ strace -p 780
strace: Process 780 attached
read(4,
Во. Программа висит на инструкции чтения только не пойми какой. Ставим для отладки на боевую поду gdb прямо в контейнер с питоновскими модулями.
$ apt-get update
$ apt install gdb python3-dbg python3-dev -y
Проверяем, что питоновский модуль подключился к gdb. Должно вывестись “ok”:
$ gdb -ex 'python print("ok")' -ex quit | tail -n 1
Подключаемся к программе по pid=780.
$ gdb -p 780
Загружаются модули и появляется приветственное сообщение.
(gdb) bt
Команда покажет сишный стек, который мало что скажет где у нас программа зависла.
Нужно загрузить инструкции для питоновой отладки. У меня Python 3.7 поэтому путь такой:
source /usr/share/gdb/auto-load/usr/bin/python3.7-gdb.py
Вызываем питоновский стектрейс:
(gdb) py-bt
Показывает текущий стектрейс и место зависания:
Traceback (most recent call first):
<built-in method read of module object at remote 0x7f0a2609d230>
(frame information optimized out)
(frame information optimized out)
(frame information optimized out)
File "/usr/local/lib/python3.7/multiprocessing/queues.py", line 352, in get
res = self._reader.recv_bytes()
(frame information optimized out)
File "/usr/local/lib/python3.7/multiprocessing/process.py", line 99, in run
self._target(*self._args, **self._kwargs)
File "/usr/local/lib/python3.7/multiprocessing/process.py", line 297, in _bootstrap
self.run()
File "/usr/local/lib/python3.7/multiprocessing/popen_fork.py", line 74, in _launch
code = process_obj._bootstrap()
File "/usr/local/lib/python3.7/multiprocessing/popen_fork.py", line 20, in __init__
self._launch(process_obj)
File "/usr/local/lib/python3.7/multiprocessing/context.py", line 277, in _Popen
return Popen(process_obj)
File "/usr/local/lib/python3.7/multiprocessing/process.py", line 112, in start
self._popen = self._Popen(self)
File "/usr/local/lib/python3.7/multiprocessing/pool.py", line 241, in _repopulate_pool
w.start()
File "/usr/local/lib/python3.7/multiprocessing/pool.py", line 248, in _maintain_pool
self._repopulate_pool()
File "/usr/local/lib/python3.7/multiprocessing/pool.py", line 412, in _handle_workers
pool._maintain_pool()
File "/usr/local/lib/python3.7/threading.py", line 870, in run
self._target(*self._args, **self._kwargs)
File "/usr/local/lib/python3.7/threading.py", line 926, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.7/threading.py", line 890, in _bootstrap
self._bootstrap_inner()
По крайней мере понятнее где примерно искать. Вспоминаем что в месте с запуском процесса и одновременным чтением потока данных может быть что-то интересное вроде дедлока и проверяем.
Например в данном случае при использовании Popen.wait() есть замечание:
Warning Use communicate() rather than .stdin.write, .stdout.read or .stderr.read to avoid deadlocks due to any of the other OS pipe buffers filling up and blocking the child process.
Вот эти команды у меня не заработали с моим бинарем, но они показывают соответственно код рядом с текущей инструкцией и локальные переменные.
(gdb) py-list
(gdb) py-locals
References
Самая классная презентация про gdb + python. В остальных очень куцо и не поясняет что делать если что-то не грузится. https://www.slideshare.net/amd4ever/debugging-python-with-gdb (Осторожно! ОРоскомнадзорено)
Ещё про доступные команды есть здесь: https://devguide.python.org/gdb/
Comments & email subscription
wholesystems.substack.com
I’m Alex, tech lead in Prestatech with experience from startups to middle-sized and big-tech companies. Loves to make effective and friendly team processes.
You can freely drop a message to [email protected] or linkedin.com/in/aptakhin to greet and ask questions about any topic.