Abstract: Реальная история из жизни реальных администраторов по отлову идиотского бага.
Поучительная часть: Никогда недооценивай зависимости зависимостей.
Вступление
Рядовой апгрейд в лаборатории с Openstack Mitaka до Openstack Newton (более новая версия). Несколько deprecated options, keystone переехал с eventlet на WSGI и поломал существующую конфигурацию с haproxy; из-за типового «ipv6 listen» apache не стал конфликтовать с haproxy за одинаковые используемые порты на звезде (один слушал ipv6, другой ipv4 only), так что запросы уходили в haproxy вместо апача, где умирали с 503, т.к. апстрима не было… Впрочем, история не об этом.
После того, как основные проблемы были пофишкены, Nova (одна из компонент Openstack) при запуске начала падать с ошибкой: ConfigFileValueError: Value for option url is not valid: invalid URI: 'http://neutron-server.example.com:21345'.. Это было очень странно. С учётом, что в конфиге поменялось 100500 опций, возникло подозрение, что мы используем устаревшую опцию (которую больше не надо использовать). Однако, документация говорила — url = http://controller:9696.
Отладка
Очевидные шаги отладки:
- Закомментировать опцию — не падает
- Повторить опцию из примера — не падает
- Заменить в опции порт на «наш» — возможно, нельзя использовать слишком большой номер порта — не падает
- Заменить в опции url на наш — падает
- Вернуть «controller» на место — не падает
- Подозрение: не умеет fqdn: заменить controller на controller.dns — не падает
- Подозрение: слишком много точек (у нас в реальном коде было 8 точек в url) — controller.dns1.dns2.dns3.dns4 — не падает
- Оставить из нашего имени только первую часть:
http://neutron-server:9696— падает! гипотеза уже понятна. - Проверка1:
http://neutronserver:9696— не падает - Проверка2:
http://with-dashes:9696— падает!
Итого, бага: наличие дефиса в hostname вызывает ConfigFileValueError. Баг репортится: bugs.launchpad.net/ubuntu/+source/nova/+bug/1653967
Проверка, что это баг: RFC3986 утвержает, что:
unreserved = ALPHA / DIGIT / "-" / "." / "_" / "~" reg-name = *( unreserved / pct-encoded / sub-delims ) host = IP-literal / IPv4address / reg-name
То есть дефис может быть в hostname. Мы это все знаем, но всегда лучше перепроверить себя.
Изучение кода, который raise ошибки:
try:
return convert(opt._get_from_namespace(namespace, group_name))
except KeyError: # nosec: Valid control flow instruction
pass
except ValueError as ve:
raise ConfigFileValueError(
"Value for option %s is not valid: %s"
% (opt.name, str(ve)))
Ошибка возникала на двух опциях: url и novncproxy_base_url. Ошибка идентичная, хотя grep'ать удобнее по второму. Начинаем искать второе:
cfg.URIOpt(
'novncproxy_base_url',
default='http://127.0.0.1:6080/vnc_auto.html',
deprecated_group='DEFAULT',
help="""
Ага. А cfg — это из from oslo_config import cfg. oslo.config — это библиотека Openstack для работы с конфигами. Смотрим сырцы.
Видим:
class URI(ConfigType):
...
def __call__(self, value):
if not rfc3986.is_valid_uri(value, require_scheme=True,
require_authority=True):
raise ValueError('invalid URI: %r' % value)
Внезапно:
>>> import rfc3986
>>> rfc3986.is_valid_uri('http://test.com')
True
>>> rfc3986.is_valid_uri('http://test-test.com')
False
Упс. Непорядок. Зато есть: github.com/sigmavirus24/rfc3986/issues/11
Бага давно пофикшена. В версии 0.2.2. А на хосте у нас:
apt-cache policy python-rfc3986
python-rfc3986:
Installed: 0.2.0-2
Candidate: 0.2.0-2
Version table:
*** 0.2.0-2 500
500 http://archive.ubuntu.com/ubuntu xenial/main amd64 Packages
100 /var/lib/dpkg/status
Зато в более свежей версии в zesty есть версия 0.3.1-2, которая такой проблемой не страдает.
Дальнейшее разбирательство
Давным-давно был сделан Баг. Он был некоторое время, потом его пофиксили. Но за это время запакетировали Код, в котором был Баг, и никто не обратил внимание на Фикс Бага, и версия с Багом оставалась в deb-репозитории годами. Она никого не волновала — пока не случились два коммита в oslo.config и nova:
commit 45ee2bed52a57b9801435b43ad45d8f50204580d
Author: Masaki Matsushita <glass.saga@gmail.com>
Date: Mon Sep 28 20:28:28 2015 +0900
Add URIOpt
This change add URIOpt which validates string as URI.
Closes-Bug: #1500398
Change-Id: Ie8736b8654b9feb2a2b174159f08dbea03568d84
commit 6091de77eda12286786e28ae4f0779e7efc54634
Author: Maciej Szankin <maciej.szankin@intel.com>
Date: Thu Jul 28 10:30:59 2016 -0500
Improve consistency in VNC opts
* Updated header flags
* Moved all vars to list
* Removed possible values and related options sections where they were not
needed
* Changed IntOpt to PortOpt where needed
Change-Id: I3255a867091f8e14c907c7fde9a2aa3abc249ae9
Implements: Blueprint centralize-config-options-newton
Этот коммит сделал из StrOpt UriOpt и начал использовать (через oslo.conf) python-rfc3986. Из-за того, что была запакетирована старая опция, в программном ПО возникла неожиданная регрессия.
Бонусное: как мы это будем фиксить
Обычно в таких случаях, если апгрейд на более новую версию даётся легко (и не вызывает других проблем), то мы просто забираем пакет из более новой версии дистрибутива (в данном случае — ещё не вышедшей zesty, ака ubuntu-17.04). Мы положим его в наш приватный репозиторий под управлением aptly (как есть) и будем его использовать при установке/настройки сервером. Если бы такого пакета не было в природе — мы бы настроили на CI джобу на его пакетирование и публикацию (в репозиторий aptly). Если бы этот вариант не был доступен (например, несовместимые изменения), то мы бы добавили в наш patchqueue для nova ещё один патч, который бы делал StrOpt вместо UriOpt. Это подразумевает, что мы будем пересобирать nova из ubuntu-пакета с нашими собственными патчами. Этим занимается CI, который публикует пакеты в тот самый наш приватный репозиторий.
Немного флейма
И как бы эта проблема решалась в проприетарной среде? Ошибки допускают все (иначе бы у нас было ПО без багов). После того, как ошибка была зарепочена в саппорт первого уровня, и после боданий про установленные версии, обновления и контракты, оно дошло бы до саппорта второго уровня, третьего уровня, и так вплоть до человека с реальной квалификацией, он бы нашёл и исправил проблему. Какой estimate для того баг-фикса? Два часа на первый уровень, ещё час на второй, business day на исследование проблемы, ещё один business day на фикс, возможно ещё один день на релиз и тестирование. Это идеальный сценарий. На практике, мои самые оптимистичные оценки говорят про недели, превращающиеся в «следующем релизе через пол-года поправили».
Сколько это заняло у меня, в opensource проекте? ~14:30, сегодня проблема обнаружилась, и я зарепортил его на launchpad. В 15:20 уже было известно про проблему с зависимостью, в 15:30 было проверено, что с новой версией python-rfc3986 этой проблемы нет. В 16:50 (по кипрскому времени) я заканчиваю писать этот пост на Хабр.
Автор: amarao
