@recoilme   2 weeks ago visitor: 37   follow: 30   favorite: 0

Прохладная история про 2-х недельный поиск ошибки в программе

Часто программисты “промахиваются” в оценке времени на задачу. Но редко настолько. Это история о том, как я 2 недели искал ошибку в работающей программе. Причем сама программа была написана дня за три)

Итак, сперва я написал базу данных. Прогнал бенчмарки. Убедился что база держит около 600к чтений/секунду и около 40к записей/сек. Это очень хороший результат, несколько микросекунд на операцию. Дело в том, что дальше оптимизировать уже нет смысла, так как например отправка и чтение запроса из перла занимает около 2 милисекунд. Затем, написал http сервер над базой и бизнес логику. Проверил утилитами ab/wrk и яндекс танком. Все выглядело прекрасно. Поехали на 10% боевого трафика.

На бою конфигурация выглядела так:

  • 36 ядерный сервер с последним поколением NVMe SSD, до жопы памяти и всё такое

  • около 900 одновременных коннектов с кучки серверов (из перла)

  • и всего около 100 запросов/сек на чтение ну и максимум с десяток на запись

Казалось бы - шоколад. База тянет 600 тысяч на макбуке, а тут жалкая сотня. И сперва все шло неплохо. Десяток запросов в час уходило в “молоко” (на самом деле нет, если запрос не успевал отработать за 10 милисекунд - отрабатывал страховочный алгоритм). Но со временем количество фолбэков (запросов не успевающих отработать за 10 мс) доросло до сотни/час. Потом до двух сотен. Конечно сперва я все валил на перловиков, но когда прошли строку за строкой с другим перловиком и не нашли ошибок - пришлось задуматься. Была идея - что дело в самом хипстерском перле. Перл работает очень странно. Там нет управления памятью или сборки мусора, он просто жрет память пока не обожрется. Когда процесс “обжирается” - его пристреливают и стартуют новый. А если один процесс не успевают - его “форкают”. Похоже на стратегию зерг раш в старкрафте или как там, когда строят сотню/тысячи дешевых юнитов и заваливат ими противника. Сдох кто то и фиг с ним - родим/наклонируем новых. Вот так примерно работает перл в хайлоаде с моей дилетантской точки зрения, отсюда и тысячи коннектов. Ну и всплески до тысячи фолбэков /в секунду я сперва объяснял тем - что пришел “начальник” - главный перловый процесс - покилял “ЗЕРГОВ” - и все одновременно ломанулись в мою базу.

Но с другой стороны это походило на отмазку. Я переписал базу данных - добавив in memory режим - в котором ничего не пишется в базу. Все живет в памяти, а на диск записывается при закрытии/остановки процесса. Выглядело изящно. Но проблемы это не решило. Количество фолбэков росло. Ок гугл. Мы переехали всем добром на боевой сервер (на нем всего 36 ядер, но на нем нет явы, которая периодически отжирает все ресурсы) И фолбэки выросли до тысячи в час. Я уже чуть не плакал где то в глубине души. Гарбэйдж коллектор. Зря я заюзал интерфейс. Gob декодер. Gin фреймворк. Зря я взял http 1.1 в качестве протокола. Зря сказал держать конеекшены открытыми. Давайте поднимем приоритет процессу. Это постгрес. Это Редис. Это свап. мы втыкаем в диск. Мы втыкаем в сеть. Я перебрал все варианты. Большинство из них сопровождалось переписыванием кода. Ничего не помогало.

Вчера, опечаленный неизбежностью втыкания профайлера в боевой сервак, снятия дампов и последующих попыток их интерпретировать - я лениво по диагонали втыкал/лупоглазил в код. И случайно наткнулся на место, в дали от основного кода, совершенно сбоку, у меня был припрятан бэкграунд сервис, который делает fsync файла каждую секунду

Дело в том, что по дефолту у меня стоял параметр - сбрасывать на диск каждую секунду. И даже при инмемори режиме, ассоциированный для дампа файл - синкался по дефолту. И даже если не было в нем записей в буфере - это все равно занимает от 20 до 200 милисекунд. В это время никто не мог ни писать ни читать из базы. И в логи валили фолбеки. Причем пока файл был меньше 8 мегабайт, синк еще быстрее делался.

Две картинки, напоследок, было

стало:

такая вот прохладная история из повседневной жизни. Две недели я пытался понять что черт возьми происходит. Когда товарищ, работающий в САП (в самой САП, не у внедренцев) рассказывал что он по месяцу ищет место в котором исправить пару строк в коде - я думал вот лохи, ну понятно САП это сотни тысяч фигово структуированного тяжкого наследия. И вот сам 2 недели искал ошибку в 500 строчной БД

Хоршие новости: гоу прекрасен. Ни одна из деталек не “фальшивит”, ни из стандартной библиотеки, ни из gin фреймворка.


@recoilme    #2 weeks ago + 0

а, забыл сказать самое главное. Я просто вырубил ежесекундный fsync. Теперь операционка сама решает когда “засейвиться”, и всё полетело..