Ищем баги с помощью 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.pyreal 0m7.412suser 0m1.102ssys 0m6.184s
Здесь
sys совпадёт с тем, что мы видели через
strace -c.
Ну и теперь даже без доступа к исходникам можно быстро понять, где «утекают» ресурсы.
Исходники у нас есть, давай посмотрим:
with open("tmp.txt", "w") as f: while True: f.write("Привет супчики! Привет от BashDays!") f.flush()
Что тут не так:Из-за
flush() Python гонит строку сразу в файловую систему, без буферизации.
Как пофиксить:# fixed.pywith 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 iobuffer = 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)
Как это работает:1.
StringIO хранит текст в оперативной памяти.
2. Цикл гонит туда строки.
3. Когда накопится, например,
1 MB, содержимое сбрасывается в файл одной большой порцией (
write +
flush).
4. Буфер очищается и цикл продолжается.
Хуй знает на сколько это всё правильно, ну раз сделали через внутреннию буферизацию
StringIO, значит так правильно.
Такие дела. Изучай.
#debug —
@bashdays @linuxfactory @blog ![Электрик [За красивой изнанкой]](/api/media/avatar/electricalnetworks)
