Ищем узкие места в проде с помощью strace
Предположим, крутится у тебя в проде какое-то приложение, это приложение было разработано криворукими обезьянами — на отъебись.
По итогу продакшен начинает троить и выжирать процессорное время. Хуита!
ЧИТАТЬ ПЕРВЫМ В ТЕЛЕГРАМЯвно требуется профилирование, но мыж с тобой не обезьяны, поэтому изучать код не будем. А сразу вооружимся strace
и посмотрим где-же узкое горлышко.
Запускаем:
strace -c python3 app.py
Через несколько секунд жмём Ctrl-C
и получаем статистику:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ------
99.82 0.413251 8 49431 write
0.07 0.000291 32 9 mmap
0.05 0.000207 25 8 mprotect
0.03 0.000129 21 6 openat
0.02 0.000090 30 3 close
......
Хм… эта падла активно пользуется системным вызовом write()
.
time
— процент процессорного времени, потраченного на вызов.
usecs/call
— среднее время на один вызов (в микросекундах).
calls
— сколько раз вызов был сделан.
Виновника определили. То есть приложение постоянно что-то куда-то пишет, тем самым забивая 99% процессорного времени.
Важно понимать: strace
показывает только то время, которое ядро тратит на обработку системных вызовов. Поэтому значения могут отличаться от того, что покажет команда time
:
$ time python3 app.py
real 0m7.412s
user 0m1.102s
sys 0m6.184s
Здесь sys
совпадёт с тем, что мы видели через strace -c
.
Ну и теперь даже без доступа к исходникам можно быстро понять, где «утекают» ресурсы.
Исходники у нас есть, давай посмотрим:
with open("tmp.txt", "w") as f:
while True:
f.write("Привет супчики! Привет от BashDays!")
f.flush()
Что тут не так:
Из-за flush()
Python гонит строку сразу в файловую систему, без буферизации.
Как пофиксить:
# fixed.py
with open("tmp.txt", "w", buffering=1024*1024) as f:
while True:
f.write("Привет супчики! Привет от BashDays!\n")
Теперь данные будут сбрасывать пачками, так как мы указали буферизацию, которая равна 1MB.
Проверяем до фикса:
$ strace -c python3 app.py
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ------
99.8 0.413251 8 49431 write
Проверяем после фикса:
$ strace -c python3 app-fixed.py
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ------
98.9 0.072111 450 160 write
Количество вызовов write()
резко сократилось, нагрузка на ядро упала.
Как костыль и быстрофикс — сойдёт! Повторюсь — мы с тобой не обезьяны, чтобы вникать в код разработчиков и что-то в нем «правильно» править.
В большинстве случаев, ты просто находишь проблемы и уже с этими данными создаешь задачу на разработчика. Сам в код не лезь, целее будешь.
Ну и на закуску фикс, который сделали разработчики:
import io
buffer = io.StringIO()
with open("tmp.txt", "w") as f:
while True:
buffer.write("Привет супчики! Привет от BashDays\n")
if buffer.tell() > 1024 * 1024:
f.write(buffer.getvalue())
f.flush()
buffer.seek(0)
buffer.truncate(0)
Как это работает:
StringIO
хранит текст в оперативной памяти.- Цикл гонит туда строки.
- Когда накопится, например, 1 MB, содержимое сбрасывается в файл одной большой порцией (
write
+flush
). - Буфер очищается и цикл продолжается.
Хуй знает на сколько это всё правильно, ну раз сделали через внутреннию буферизацию StringIO
, значит так правильно.
Такие дела. Изучай.