У вас бывают в разработке такие периоды, когда что-то в коде идет не так, ты ищешь баг, а потом оказывается, что за ним стоял еще один баг? Мне нравится искать баги. Это создает ощущение, словно ты Шерлок Холмс и являешься главным героем в детективе, где кто-то из обширного списка на вид безобидных классов и функций вызывает неожиданное и даже неопределенное поведение программы, а ты своим зорким взглядом и экспериментами пытаешься вычислить этого мерзавца в кратчайшие сроки.
Мы опубликовали и перевели эту статью с разрешения правообладателя. Автор статьи – Евгений Захаров (fnc12@me.com). Оригинал опубликован на сайте Habr.
Можно выделить несколько стадий поиска бага:
Меня зову Женя, я open source разработчик. Я занимаюсь разработкой библиотеки sqlite_orm на С++ в свое свободное время.
Библиотека sqlite_orm предоставляет более удобный API на С++, чем "родная" SQLite3-библиотека, написанная на чистом С. Конечно, я и другие контрибьюторы еще не покрыли весь API SQLite, потому работа не останавливается никогда. Меня очень давно просили добавить в sqlite_orm поддержку пользовательских функций. Это возможность привязывать колбэки на чистом C в виде функций, доступных внутри SQLite-запросов. И вот я решил, что хватит тянуть кота за хвост, что когда-нибудь все-равно придется взяться за это, а значит почему бы не взяться за это прямо сейчас? Сказано - сделано. Я сел, начал кодить. Фича состоит из условных трех частей:
Я честно сделал все три шага. Это было три последовательных пулл-реквеста. И если коротко, то третий ПР я так и не влил все еще, потому что с ним начали происходить, если выражаться мягко, волшебные странности.
AppVeyor вдруг стал говорить, что юнит-тесты упали. Хм, ок, я пошел смотреть. Конечно, меня это удивило, потому что локально все проходило.
Однако локально я работаю на macOS, а AppVeyor мне собирает Windows. Значит ошибка платформозависимая, а это значит, что на носу у меня "веселая" детективная история, потому что платформозависимые ошибки самые вредные. Однако я даже представить себе не мог, во что это все выльется.
Ок, смотрю я в логи AppVeyor. Логи говорят: 1 тест не пройден. Ок, смотрим какой тест. Ответ: тот самый, который я добавлял вместе с пользовательскими функциями. Если точно, то вот логи:
[НАЧАЛО БЛОКА SPOILER]
Для тех, кому интересны технические детали того, что тут происходит:
Запрос SELECT FIRST('Vanotek', 'Tinashe', 'Pitbull'), где функция FIRST — это скалярная функция с варьирующимся количеством аргументов, которая принимает строки и возвращает строку, состоящую из первых символов всех аргументов в том же порядке, в котором они подставлены в функцию. На маке результат равен "VTP", что логично, а вот на венде - нет.
[КОНЕЦ БЛОКА SPOILER]
Я в недоумении, ругаюсь на венду, думаю забить на ее поддержку, удалить этот юнит-тест и влить ПР как есть. Но я успокаиваюсь, отбрасываю дурацкие мысли и начинаю пытаться найти причину косяка.
Давайте я не буду описывать подробности того, что было дальше. Расскажу коротко. Я сначала добавлял cout логи чтобы посмотреть на то, что происходит прямо на AppVeyor и по-быстрому решить проблему. Не вышло. Потом я таки расчехлил свою венду, собрал проект в Visual Studio и стал дебажить (к счастью, на моей венде баг тоже воспроизводился). В общем, косяк оказался в том, что когда для результата отдаем строку, то ее надо копировать и предоставлять указатель на функцию-деструктор. Самое забавное в этом баге то, что в процессе дебага я долго не мог понять, почему целые числа отлично заходят в качестве результата, а строки ломаются. При этом только на венде. Мак, как я и говорил, стабильно выдавал мне 0 непройденных тестов. Я даже в процессе написал одному из разработчиков SQLite о том, что я нашел ошибку в SQLite, которая воспроизводится только на венде. Потом, когда я уже понял в чем косяк, я отписался ему вновь о том, что я сам дурак: "извини меня за беспокойство и за то, что я закидал тебе личку кусками своего кода".
Это был очень глупый баг, в котором был виноват исключительно я сам, а не коллеги по проекту, не github, не сторонние либы и не компилятор. Я сглупил, отвык писать на чистом C и просто ослеп на подобные баги. Вообще, если ты, дорогой читатель, вдруг думаешь, что если у человека есть open source проект с 1000+ звездами, то этот человек какой-то по-особому умный, то я тебя огорчу — это совсем не так. Я порой пишу такую дичь, что мне больше интересно понять почему в моей голове происходят такие когнитивные искажения, чем писать непосредственно код. И то насколько я хороший код пишу зависит не от количества звезд у sqlite_orm, а от простого "выспался или нет" и "устал ли я от прогулки под палящим алмаатинским солнцем сегодня".
Однако если бы мне на данном этапе, когда я уже поправил этот глупый баг, сказали, что самое интересное еще впереди и что сейчас я приблизился к самому эпичному багу, к боссу всех багов, нет, к боссу всех боссов всех багов, которые были за всю историю существования библиотеки sqlite_orm, то я бы точно в это не поверил.
Но вернемся ко мне в то время, когда я только поправил баг. Я чувствую себя одновременно и болваном, и героем. Болваном — потому что баг глупый. Героем — потому что наконец-то у меня пройдут проверки пулл-реквеста на AppVeyor и я наконец-то волью полностью поддержку пользовательских функций. Пока юнит-тесты выполнялись, я размышлял об этом баге. В частности, о том, почему он стабильно не воспроизводился на маке. На самом деле, я часто с таким сталкивался. Вообще, следует признать, что macOS + iOS более толерантны к неопределенному поведению, чем Windows. Ведь, по сути, я передавал указатель на строку, которая "умерла" уже к тому моменту, когда надо было к ней обратиться. Однако память не только осталась у процесса, но и сохранила свое содержимое. И она сохраняла его каждый раз, когда я запускал юнит-тесты на маке. То есть, мак порой превращает неопределенное поведение в определенное.
И вот вы представьте, насколько я не мог поверить своим глазам, когда увидел, что проверки вновь не прошли. Я всегда был убежден, что выражение "не верю своим глазам" имеет переносный смысл, но в ту минуту я буквально не верил своим глазам. Я думал, что глаза у меня тоже глючат, как глючил мой мозг, когда я сотворил тот глупый баг, что на самом деле проверки прошли и ПР можно смело вливать, просто что-то не так с моими глазами. Однако проверки не прошли, это был факт. "Ну, наверное это какая-то сторонняя ошибка" - подумал я, - "наверное, коммит последний не подтянулся, сеть глючит у AppVeyor, на билд-агент упал метеорит, но мой код точно не имеет багов". Как же я ошибался в тот момент.
Я пошел на страницу деталей прогона ПР в AppVeyor. И увидел в этот раз знакомую картину: все 8 прогонов снова красные. Как если бы я ничего не коммитил! Но я коммитил! Я снова прокрутил в голове те моменты, когда я делал коммит. Я точно его делал, я не сошел с ума пока. Ок, пойдем в логи. Вот что показывают логи:
Логи говорят, что сломались тесты фичи custom collations. Фичи никак не связанной с пользовательскими функциями. Custom collations — это похожая на пользовательские функции фича, однако не имеющая ничего общего в реализации с ними. Custom collations позволяет добавлять свои collating последовательности, которые вызываются как колбэки для функций на чистом C, которые используются для сравнения строк. Повторюсь: никакой связи эти две фичи не имеют. Я могу смело выкинуть любую, и вторая останется работоспособной. Контейнеры, в которых хранится информация о пользовательских функциях и коллэйшонов, тоже разные (типы разные), а значит я не мог по ошибке отдать итератор на один контейнер в другой.
Я думаю "ок, вот тут точно мой ПР про функции не при чем". Значит, основная ветка разработки 'dev' тоже должна показывать эту ошибку. Однако в ветке 'dev' все было прекрасно - 8 зеленых прогонов. Значит дело в пользовательских функциях. Но как могут функции аффектить коллэйшоны? И почему только на венде, а не на маке? Я готов был рвать волосы на своей голове, но у меня их и так там нет. Я готов был признать свою профнепригодность и пойти работать кем-либо еще. Может это снова толерантность к неопределенному поведению случилась? Дважды за день! Но почему тогда в ветке 'dev' на Windows все работает? Фича custom collations была влита три года назад по просьбе пользователей библиотеки. Не может быть такого, что никто из этих людей не заметил, что коллэйшоны не работают.
Ок, я немного успокоился и пошел смотреть в код. Я вам его тоже покажу. Попробуйте найти в нем ошибку.
Если вы догадались, то вы супер. А я не догадался. Точнее, догадался только вчера. А до этого три ДОЛБАННЫХ года (!) этот код работал неправильно.
[НАЧАЛО БЛОКА SPOILER]
В чем именно косяк в данном коде:
На строке 323 второй аргумент функции, который называется f, отдается полностью в местный контейнер при помощи std::move, а значит после этого f будет пустым (f это std::function), а значит на строке 335 в тернарном операторе всегда будет возвращаться альтернативный результат, а не основной. В таком случае, вместо создания коллэйшона с указанным именем будет вызвано его удаление.
[КОНЕЦ БЛОКА SPOILER]
Ок, вот мы и нашли причину ошибки "no such collating sequence". Давайте править код. Я, все еще немного офигевая от того, что у меня баг вылез из-за новой несвязанной фичи, влил исправление, чтобы наконец-то тесты на венде прошли успешно. Я запушил и в ожидании сборки юнит-тестов на AppVeyor стал обдумывать ситуацию. Все же раньше собиралось! И на венде тоже! И другие разработчики пользовались всем этим, и никто не жаловался. Что ж, у меня есть где-то час пока дойдет очередь до сборки моего ПР. Ждем.
Вы, наверное, думаете: "Женя, ну и что? Это самый эпичный баг?". Но вы подождите, еще не конец!
Когда сборка закончилась, как вы думаете, какой был результат на AppVeyor? Правильно, красный. А знаете какие тесты не прошли? Вот вам картинка:
"Выглядит как какая-то ерунда", - подумал я сразу же. Ну тут точно что-то произошло на билд-агентах. Если серьезно, то бывает, что SQLite не смог скачаться — wget не сумел отработать, и из-за этого не проходит сборка. Но (спойлер) ничего такого не случилось. И в дальнейших моих коммитах, где я добавлял выводы логов, результат был идентичным: эти же три из восьми конфигураций не проходили. "Что же там не так?", спросите вы. Вот:
Снова тот же тест, но уже с другой ошибкой. Если раньше SQLite не мог найти collating sequence, то теперь он находит эту collating sequence, но она не отрабатывает, из-за этого в контейнере 'rows' пусто, хотя должна быть одна запись.
Фак, фак фак! Как так?! Почему опять я делаю пользовательские функции, но ломаются коллэйшоны? Почему такая логика? Почему в 'dev' все работает? Почему только венда? Почему так много "почему"? Я, конечно, люблю детективы, но тут очевидно, что закон подлости насмехается надо мной.
Ладно, хватит переживать, надо скорее искать косяк. Не буду рассказывать, как долго я искал косяк, просто расскажу, где он оказался. Вот код:
Это код теста. Лямбда должна осуществлять сравнение строк и возвращать индекс первого несовпадающего символа по аналогии с функцией strcmp. И я проигнорировал первый аргумент, который имеет тип int. Это длина данных для сравнения. И SQLite не дает гарантию, что второй и третий аргументы имеют после себя нуль-терминаторы. Просто почему-то раньше эти нуль-терминаторы там были. Целых три года! Но с появлением пользовательских функций три из восьми конфигураций на Windows вдруг перестали проявлять толерантность к неопределенному поведению. К такому жизнь меня точно не готовила.
Заменив код на вот такой, я добился, что все тесты стали проходить как надо:
Что имеем в итоге? Если опустить глупую ошибку с копированием C-строки, то новая фича вдруг выявила совершенно не связанные проблемы, которые были в виде кода, который ведет себя неопределенно в теории, но на практике три года вел себя очень определенно (по крайней мере тесты выполнялись и крэшей не было). Я эту особенность называю "толерантностью к неопределенному поведению". На данный момент это самое долгоживущее в sqlite_orm неопределенное поведение. Это неопределенное поведение, пронесенное сквозь года. Возможно, вы ожидаете от меня каких-то выводов и напутствий. Их не будет. Я просто поделился с вами историей, как если бы мы просто сидели за кружкой пива в цельте на Октоберфесте, или наблюдали за закатом в походе на Алтае, или случайно ехали вместе в одном купе в Тальго из Тбилиси в Батуми. Я ни в коем случае не писал это, чтобы показать какой С++ плохой. Я в первую очередь хотел показать к чему могут привести глупые ошибки в коде, которые совершил ты сам, а не коллеги по проекту, не github, не сторонние либы и не компилятор.
Всем спасибо за прочтение, и желаю всем зеленых сборок!
