Представьте, что вы разрабатываете проект на Го и для работы с данными используете MySQL, общаясь с ним ванильно через “database/sql” и “github.com/go-sql-driver/mysql” без каких-либо орээмок.
Проект растет, ваши тесты в нем тоже растут, идет время (например, год) и, вдруг, вы наталкиваетесь на очень странное поведение: тесты падают с ошибкой: Error 1049: Unknown database ‘xxx’
Вы идете в Мускул и замечаете, что все базы на месте. И даже таблицы в них все созданы правильно. Очень странно.
Вы запускаете тесты еще раз, та же самая ошибка. Еще раз — ничего нового, опять ошибка 1049, нет базы и все. Но она есть! Вы, не веря консольному mysql client, поднимаете в докере рядом phpMyAdmin, идете в базу и наблюдаете наличие баз.
Чтобы постараться продебажить или как-то сузить поиск ошибки, вы решаете запустить падающий тест отдельно. Запускаете… ошибки не происходит!
WUUUUT?
Запускаете под-группу тестов — все ок! Запускаете опять все тесты через go test ./… и опять ошибка с несуществующей базой данных.
Тут приходит мысль все рестартить. Я обычно поступаю так в каких-то совершенно неопределенных ошибках, на которые влияет солнечная интерференция. Начинаю рестартить докер контейнер в котором крутиться Мускул и решаю запустить его так, чтобы он в консоль вываливал весь свой лог во время работы.
Начинаю замечать, что при ошибке с несуществующей базой в тестах в логах Мускула появляется вот такая запись [Note] Aborted connection 7 to db: ‘unconnected’ user: ‘root’ host: ‘172.20.0.1’ (Got an error reading communication packets)
Круто, уже есть хоть какая то закономерность. Идем гуглить эту ошибку и натыкаемся на вот эту ишью в Гитхабе: https://github.com/docker-library/mysql/issues/124. Смотрим на заголовок и понимаем, что это наш случай, конечно… Докер и Мускул :)
Читаем камменты и ничего кроме нытья не можем нарулить, окромя чувака, который сообщает следующее: I found the problem: The MySQL container was running twice. Had to docker-compose stop the project and make sure only one container is running at a time.
Хммм. Я решаю основательно вырубить все любые запущенные контейнеры командой docker stop $(docker ps -a -q)
Запускаю один Мускул и — офигеть — тесты проходят!
Я смотрю лог Мускула, там ничего нет про ошибки, запускаю опять все тесты и они проходят. Радости нет предела. Теперь думаю перезапущу контейнер для порядка, запущу тесты еще раз и начну копать в сторону того, откуда там у меня на рабочей машине появились лишние Мускульные контейнеры.
И что вы думаете? Ошибка вернулась! Во всем Докере всего лишь один контейнер и это Мускул. Те же самые ошибки в логах Мускула. Та же самая ошибка в тестах про несуществующую базу.
WUUUUT?
Начинаю Гуглить дальше. И нахожу волшебную статью в блоге Перконы (ребята, привет!). https://www.percona.com/blog/2016/05/16/mysql-got-an-error-reading-communication-packet-errors/ В статье описываются причины появления этих ошибок и меня привлекает следующая штука: The client connected successfully but terminated improperly (and may relate to not closing the connection properly)
И тут я понимаю, что я ведь пишу код на Го, а не на Похапе и, возможно, просто все время клал за закрытие коннекшенов или дескрипторов. Когда проект был не большой, то ничего не было заметно. Вот проект вырос, выросло число тестов и количество незакрытых дексрипторов перевалило за какую-то настройку, что в результате начало тригерить ошибку.
Непонятно, конечно, почему ошибка именно в отсутствии базы данных. Я думаю, что это либо кривая реализация гошной либы. Ты же ждешь ошибку, типа, too many connections или not enough descriptors
Однако, такое поведение может быть и легитимным, так как при соединении мы указываем базу данных и когда соединение отваливается после того, как успешно было создано, то — да, клиент думает, что пропала база. Ну фиг его знает как на самом деле.
Открываю свой код и вижу, что нигде не вызывается закрытие prepared statement после использования. То есть, я делаю stmt, err := db.Prepare(“sql”), а defer stmt.Close() не делаю.
Открыв исходник функции Prepare читаем:
В общем, расставил закрытия стейтментов и ошибки пропали. Надеюсь, кому-то поможет эта статья. Мне пришлось провозиться с этой ошибкой пару дней с очень удивленным выражением лица
Я на радостях прошу своего тиммейта запулиться с репозитория и запустить тесты. Через 3 минуты он высылает мне точно такую же ошибку с несуществующей базой о_О. Я запускаю тесты у себя и — да — у меня тоже самое!
WUUUUT? (っ ºДº)っ ︵ ⌨️
Продолжаю гуглить и нахожу прекрасный сайт про волшебную либу database/sql -> http://go-database-sql.org/
Там есть статья http://go-database-sql.org/surprises.html где рассказывается о том, что под капотом, и что коннекшены к базе не создаются сразу, а что релизить коннекшены нужно не постоянно (как в древнем Похапе), а редко, желательно когда софт заканчивает свою работу. Что запросы, которые идут друг за другом могут выполняться в разных коннекшенах, и для того, чтобы группа запросов юзала один контекст соединения, нужно оборачивать критичный код в транзакию.
Что я и сделал. Очищение и создание фикстур сделал super safe, но все равно попадаю на те же ошибки с несуществующей базой, причем в разных местах.
Тут я понимаю, что мой запрос, который чистит базу, возможно, в корне кривой и это жуткий антипаттерн. Делаю я это так: “DROP DATABASE IF EXISTS db_name; CREATE DATABASE db_name”. Где-то в глубине роются мысли о том, что может глючить мультистейтмент. ОК, переделываем на два запроса: все равно появляется ошибка о несуществующей базе.
Хорошо, меняем этот вариант на более простой. Не удаляем/создаем базы, а просто дропаем там таблицы. Чекаем и видим нерегулярные, в разных местах всплывающие ошибки о НЕСУЩЕСТВУЮЩИХ ТАБЛИЦАХ!
Вспоминаю, что запуская тесты по одному, таких ошибок нет. Удостоверяюсь в этом запуская все модули через go test друг за другом. Все выполняется. Долго, но выполняется.
Оказывается, когда вы запускаете go test ./…, то Го пытается запустить тесты по модулям параллельно, раскидывая выполнения по ядрам. Можно регулировать это поведение через ключ parallel, но в моем случае “ — parallel 1” выкидывал такие же рандомные ошибки.
Ошибки не появляются и все тесты проходят если в Makefile в команде :test просто перечислить все модули друг за другом командой go test
Прихожу к выводу о том, что это какие-то неочевидные race conditions, либо ошибки связанные с ними всегда неочевидные.
Пока не разобрался как это чинить и куда копать. Решил оставить выполнение тестов друг за другом, а не параллельно.
Ранее этв статья была опубликована тут.