Из любого правила бывают исключения… ????
Одним из трендов при проектировании сервисов в последнее время выступает использование в качестве баз данных NoSQL-систем. Мы также стараемся идти в ногу со временем и, конечно же, имеем в своем IT-ландшафте несколько таких решений. Одно из них — шардированный кластер MongoDB. Эксплуатация этой СУБД сопряжена с проблемами производительности, архитектуры, взаимодействия и т.д. Удивительно, но факт - зачастую, все мы сталкиваемся с тем, что ошибаются разработчики самой СУБД. Кто бы мог подумать.., что после штатной перезагрузки узла конфигурационного сервера MongoDB в процессе обновления может произойти аварийное завершение работы сервиса базы данных и наш стенд превратится в «тыкву»!
Об одном из таких случаев хотим рассказать в этой статье и, возможно, уберечь наших читателей от опрометчивых шагов при работе с MongoDB.
Дисклеймер: нижеописанные события произошли после того, как была опубликована рекомендация производителя не использовать версию 4.4.4.
Начало
Как это часто бывает, все случилось в процессе штатной процедуры - обновления. Версия 4.4.4, как известно, с недавних пор не рекомендуется вендором для использования в промышленных контурах, так как имеет выявленные дефекты. В нашем случае периодически падали балансировщики mongos, а это значит, что работы по апгрейду были неизбежны, как смерть и налоги. В качестве целевой выбрали версию 4.4.9 и приступили к подготовке.
Немного забегая вперед, скажу, что от серьезных последствий нас и уберегла эта подготовка. Как и все серьезные айтишники , мы сначала тестируем новую версию ПО и только в случае успеха на тестовом стенде - производим миграцию на новую версию продуктивной инсталляции.
Хьюстон, у нас проблемы…
Cолнечное ноябрьское утро было омрачено фактом того, что при обновлении тестового стенда в процессе перезапуска узла конфигурационного сервера MongoDB с ролью primary произошло аварийное завершение работы сервиса базы данных на нем, после чего он наотрез отказался запускаться, выдавая вот такую ошибку:
{"t":{"$date":"2021-11-06T17:42:14.771+03:00"},"s":"F", "c":"-", "id":23079, "ctx":"ConfigServerCatalogCacheLoader-0","msg":"Invariant failure","attr":{"expr":"chunkVersion >= collectionVersion","file":"src/mongo/s/chunk_manager.cpp","line":614}}
{"t":{"$date":"2021-11-06T17:42:14.771+03:00"},"s":"F", "c":"-", "id":23080, "ctx":"ConfigServerCatalogCacheLoader-0","msg":"\n\n***aborting after invariant() failure\n\n"}
{"t":{"$date":"2021-11-06T17:42:14.771+03:00"},"s":"F", "c":"CONTROL", "id":4757800, "ctx":"ConfigServerCatalogCacheLoader-0","msg":"Writing fatal message","attr":{"message":"Got signal: 6 (Aborted).\n"}}Случившееся, разумеется, привело к тому, что развалился replica set и тестовый стенд «впал в кому».
Такие попытки решения проблемы как: перезапуск кластера, перестроение индекса, на который были ссылки в сообщениях о дубликатах записей, и даже откат на версию 4.4.4 - не возымели никакого эффекта. Последнее (в худшем смысле) стало для нас полным сюрпризом.
«Раз откат не помогает давайте попробуем развернуть копию машины конфигурационного сервера и обойти таким образом ошибку конфликта данных при создании replica set!» - подумали мы. Сказано – сделано, эффект - нулевой. Решение устранить проблему добавлением ноды было уже не столько осознанным выбором, сколько попыткой предпринять хоть-какие-то действия в условиях полного непонимания причин происходящего.
Поддержка вендора хранила загадочное молчание, а мы всерьез подумывали купить шаманский бубен и устранить проблему, прибегнув к помощи духов предков.
Эврика!
Как оказалось, наши разработчики все это время не сидели на месте, а уже несколько часов изучали исходные коды MongoDB. Это принесло плоды - гипотезу о том, что причиной может являться битый системный индекс:
Invariant failure, chunkVersion >= collectionVersion
{"t":{"$date":"2021-11-06T13:27:04.411+03:00"},"s":"F", "c":"-","id":23079,"ctx":"ConfigServerCatalogCacheLoader-1","msg":"Invariant failure","attr":{"expr":"chunkVersion >= collectionVersion","file":"src/mongo/s/chunk_manager.cpp","line":614}}
Если это правда, оставалось только его найти, т.е. найти иголку в стоге сена.
Решение появилось и тут – встроенная утилита validate, с помощью которой мы выяснили, что гипотеза, выдвинутая разработкой верна и у нас нарушен порядок сортировки индекса ns таблицы config.chuncs:
> db.chunks.validate({full: true})
{
"ns" : "config.chunks",
"nInvalidDocuments" : 0,
"nrecords" : 7060658,
"nIndexes" : 4,
"keysPerIndex" : {
"ns_1_min_1" : 7060658,
"ns_1_shard_1_min_1" : 7060658,
"ns" : 7060678,
"_id_" : 7060658
},
"indexDetails" : {
"ns_1_min_1" : {
"valid" : true
},
"ns_1_shard_1_min_1" : {
"valid" : true
},
"ns" : {
"valid" : false
},
"_id_" : {
"valid" : true
}
},
"valid" : false,
"warnings" : [
"Detected 20 extra index entries."
],
"errors" : [
"Index with name 'ns' has inconsistencies."
],
"extraIndexEntries" : [
{
"indexName" : "ns",
"recordId" : NumberLong(688647),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(22086, 534123)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(535562),
"indexKey" : {
"ns" : "db”
"lastmod" : Timestamp(29329, 5404918)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(360777),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5462226)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(1315),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5469432)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(180775),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5483800)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(580654),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5496988)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(538481),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5501174)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(284061),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5509100)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(398145),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5534858)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(430671),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5552776)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(665753),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5580528)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(279081),
"indexKey" : {
"ns" : "db",
"lastmod" : Timestamp(29329, 5743408)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(153320),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1401600)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(138821),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1460896)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(97659),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1466972)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(240192),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1471200)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(169250),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1478594)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(97863),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1486242)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(145160),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1496736)
}
},
{
"indexName" : "ns",
"recordId" : NumberLong(403131),
"indexKey" : {
"ns" : "db-test",
"lastmod" : Timestamp(11108, 1499176)
}
}
],
"missingIndexEntries" : [ ],
"advice" : "A corrupt namespace has been detected. See http://dochub.mongodb.org/core/data-recovery for recovery steps.",
"ok" : 1
}
После перестроения испорченного индекса сервис заработал как надо : db.getSiblingDB("config").chunks.reIndex(); Мы, конечно же, ликовали, но оставалось разобраться в глубинных причинах произошедшего.
Разбор полетов
Анализ произошедшего позволил сделать вывод о том, что, так как версия MongoDB 4.4.4 не рекомендуется вендором для использования в промышленных контурах, ввиду наличия выявленных дефектов, битый системный индекс может быть одним из её артефактов, который не проявлялся до момента рестарта в процессе обновления.
А это значит, что наша продуктивная инсталляция MongoDB версии 4.4.4, весьма вероятно, остается работоспособной ровно до момента перезагрузки, то есть стоит на «пороховой бочке». Приняв изрядную дозу корвалола, мы отправились заниматься перестроением испорченных индексов уже на продуктиве.
Выводы
Гипотеза о битом индексе была не случайным стечением обстоятельств, а результатом нашего труда – для решения проблем стоит привлекать все возможные ресурсы.
Несмотря, на то, что в рекомендациях вендора данный пункт отсутствует – проверяйте индексы на целостность. К счастью, утилита validate (https://docs.mongodb.com/manual/reference/method/db.collection.validate/) позволяет не делать этого в ручном режиме.
Еще раз похвалите себя за то, что вы тестируете новые версии софта перед установкой в прод.
Поддержка вендора – не панацея, решения по открытому нами кейсу (https://jira.mongodb.org/browse/SERVER-61303) на 10.11.2021, пока нет.
Спасибо за внимание, желаем вам соблюдения всех SLA ????
Автор: Евланов Александр
Комментарии (4)
zhulanchik
03.12.2021 15:55Расскажите подробнее о истинных падениях прода МДЛП в октябре прошлого года и последующих дырах в БД. Что тогда случилось?
chestny_znak Автор
06.12.2021 10:01Спасибо, за идею для статьи - наша команда рассмотрит эту тему и, если обнаружит в ней пользу для сообщества Хабра, то такая публикация обязательно появится
opertseva
Очень клево написано ????