Zimbra не поднялась после апгрейда: три причины за один вечер

Медклиника на Авиамоторной, 16 рабочих мест, вечер пятницы. Их приходящий админ запустил обновление Zimbra в 18:20, ушёл в 19:00 и перестал брать трубку. Почта не работала. В понедельник с восьми утра — приём, а запись пациентов у них шла в том числе письмами из страховых. Меня нашли около восьми вечера через знакомых. Дальше был вечер, в котором один и тот же симптом три раза оказался следствием разных причин, и полтора часа я потратил впустую.

Сценарий повторяется из года в год. Обновление ставят вечером в пятницу, потому что «никто не работает и до понедельника есть время». Логика понятная. Ломается она в тот момент, когда человек, запустивший апгрейд, уезжает, а служба не поднимается — и рядом не оказывается никого, кто читал бы логи Zimbra раньше.

Если вы держите почтовый сервер, который боятся трогать, и обновление откладывается годами именно из-за страха «а вдруг не встанет» — этот текст ровно про ваш случай. Он не про то, как всё пройдёт гладко. Он про то, что делать, когда не встало.

Клиника работала на Zimbra 8.7.11. Обновляли до 8.8.12 — дистрибутив лежал у них на файловом сервере ещё с позапрошлого года, его скачал прежний админ. Я к тому моменту, когда добрался до консоли, знал только время старта апгрейда и то, что zmcontrol status ругается. Было 20:10, май 2021-го.

Служба висела наполовину. Часть компонентов Zimbra поднялась, mailboxd — нет. Это, кстати, худший вариант из возможных: сервер выглядит живым, порт 25 отвечает, письма даже принимаются в очередь, но в ящики не ложатся и веб-клиент не открывается.

su - zimbra
zmcontrol status
#   Host mail.klinika.local
#     amavis                  Running
#     antispam                Running
#     antivirus               Running
#     ldap                    Running
#     logger                  Running
#     mailbox                 Stopped
#     mta                     Running
#     opendkim                Running
#     snmp                    Running
#     spell                   Running
#     stats                   Running
#     zmconfigd               Running

zmmailboxdctl status
# zmmailboxdctl is not running.

Диск на месте, свободного 41 ГБ из 200. Память — 12 ГБ, свободно почти половина. Нагрузки нет вообще, load average 0,3. То есть банальные причины отпадали сразу, и это меня, честно говоря, немного расслабило: я решил, что дело в чём-то смысловом, и полез читать не тот файл.

Открыл /opt/zimbra/log/mailbox.log — главный Java-лог, куда я привык смотреть. Последняя запись в нём была в 18:19, за минуту до старта апгрейда. Дальше пусто.

Я сделал вывод, который казался очевидным: mailboxd падает так рано, что даже не успевает написать в свой лог, а значит проблема ниже — в базе. Проверил MariaDB, посмотрел, поднимается ли mysql.server status, прогнал zmdbintegrityreport -v, полез в схему. База была здорова. Полтора часа ушло.

Ошибка была вот в чём. mailbox.log пишет приложение внутри JVM. Если JVM не стартовала вовсе, писать в него некому — и пустой лог означает не «упало рано», а «даже не начало». Стартовый лог самой JVM живёт отдельно:

tail -50 /opt/zimbra/log/zmmailboxd.out
# OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated
#   in version 9.0 and will likely be removed in a future release.
# Unrecognized VM option 'PrintGCDateStamps'
# Error: Could not create the Java Virtual Machine.
# Error: A fatal exception has occurred. Program will exit.

Вот и всё. Три строки, которые я мог прочитать в 20:15, а прочитал в 21:50. Правило, которое я с тех пор не нарушаю: при несостоявшемся старте mailboxd первым открывается ~zimbra/log/zmmailboxd.out, и только потом mailbox.log.

Что произошло. В localconfig.xml у клиента лежали java-опции, добавленные когда-то руками — сборщик мусора CMS и печать меток времени в GC-логе. На 8.7.11 они работали. Апгрейд принёс другую Java, в которой UseConcMarkSweepGC объявлен устаревшим, а PrintGCDateStamps просто не распознаётся. Незнакомая опция для JVM — фатальная ошибка, она не стартует вообще.

Лечится это правкой одного параметра. Смотрим, что там сейчас, и убираем лишнее:

zmlocalconfig -s mailboxd_java_options
# mailboxd_java_options = -server -Djava.awt.headless=true -Dsun.net.inetaddr.ttl=600
#  -XX:+UseConcMarkSweepGC -XX:PermSize=128m -XX:+PrintGCDateStamps -verbose:gc ...

# оставляем только то, что понимает текущая JVM
zmlocalconfig -e mailboxd_java_options='-server -Djava.awt.headless=true -Dsun.net.inetaddr.ttl=600 -verbose:gc -Xss256k'
zmmailboxdctl restart
tail -f /opt/zimbra/log/zmmailboxd.out

Здесь есть тонкость, из-за которой правку иногда делают дважды. Значение по умолчанию Zimbra формирует сама на основе версии; если вы когда-то переопределили параметр целиком, апгрейд ваше переопределение не тронет — он не знает, что там ваше, а что его. Поэтому после каждого мажорного обновления имеет смысл сравнивать свои java-опции с дефолтными для новой версии, а не хранить их как реликвию с 2016 года.

Отдельно замечу про 8.8.12: связка «устаревшая опция GC плюс новая JVM» — известная ловушка именно этой версии. Мы через неделю ушли с неё на 8.8.15, которая к тому моменту была доступна уже почти два года. Это, кстати, тоже была моя недоработка — я не спросил в первый вечер, откуда взялся дистрибутив, и чинил ровно то, что стояло.

JVM завелась, mailboxd поднялся, я выдохнул — и на очередном рестарте получил новое:

zmcontrol start
# Can't kill a non-numeric process ID at /opt/zimbra/bin/zmstatctl line 204.

Причина — осиротевшие PID-файлы. Апгрейд шёл через жёсткую остановку служб, часть файлов /opt/zimbra/log/*.pid осталась от процессов, которых уже нет, а внутри одного из них лежал мусор вместо числа. Скрипт пытается прочитать PID и убить процесс, получает не число и падает.

# убеждаемся, что живых процессов нет
ps -u zimbra -o pid,comm | grep -E 'java|slapd|master|mysqld'
ls -la /opt/zimbra/log/*.pid
cat /opt/zimbra/log/zmstat.pid
# (пусто / мусор)

# убираем осиротевшие PID-файлы и стартуем нормально
mkdir -p /tmp/pid-backup
mv /opt/zimbra/log/*.pid /tmp/pid-backup/
su - zimbra -c 'zmcontrol start'

И вторая половина той же истории. Ночью я поймал себя на том, что пару команд запустил от root — сидел в root-сессии, устал. Zimbra этого не любит: zmcontrol, zmprov, zmlocalconfig должны идти строго из-под пользователя zimbra. Запуск от root оставляет за собой файлы с чужим владельцем, и следующий старт из-под zimbra спотыкается уже об это. Проверять так:

find /opt/zimbra/log /opt/zimbra/data -not -user zimbra -ls | head
# если находится — чинится штатно, от root:
/opt/zimbra/libexec/zmfixperms

Мне повезло: файлов оказалось три, все в логах, и zmfixperms отработал за две минуты. Не повезло бы — разгребал бы права по всему дереву.

Третий заход был в 00:40. Служба стартовала, но веб-клиент отдавал ошибку, а в логе всплывал keystore. У клиники стоял коммерческий сертификат, поставленный полтора года назад, и после апгрейда он с новым хранилищем ключей не подружился.

Схема лечения, которая работает и которую я с тех пор применял ещё дважды: вернуть самоподписанный, убедиться, что сервер в таком виде живой, и только после этого закатать коммерческий заново.

# от root — только права на файлы; сам zmcertmgr из-под root не работает
# и отвечает: zmcertmgr: ERROR: no longer runs as root!
chown zimbra:zimbra /tmp/commercial.crt /tmp/chain.crt
chmod 644 /tmp/commercial.crt /tmp/chain.crt

# дальше всё из-под zimbra
su - zimbra -c '/opt/zimbra/bin/zmcertmgr viewdeployedcrt'

# шаг 1 — временно самоподписанный, чтобы поднять сервис
su - zimbra -c '/opt/zimbra/bin/zmcertmgr createcrt -new -days 365'
su - zimbra -c '/opt/zimbra/bin/zmcertmgr deploycrt self'
su - zimbra -c 'zmcontrol restart'

# шаг 2 — обратно коммерческий, цепочкой целиком
su - zimbra -c '/opt/zimbra/bin/zmcertmgr verifycrt comm /opt/zimbra/ssl/zimbra/commercial/commercial.key /tmp/commercial.crt /tmp/chain.crt'
su - zimbra -c '/opt/zimbra/bin/zmcertmgr deploycrt comm /tmp/commercial.crt /tmp/chain.crt'
su - zimbra -c 'zmcontrol restart'

Здесь я в ту ночь потерял ещё десять минут ровно потому, что сидел в root-сессии: на 8.7 и старше zmcertmgr из-под root просто отказывается работать и отвечает zmcertmgr: ERROR: no longer runs as root!. От root в этом блоке остаются только chown и chmod, всё остальное — через su - zimbra -c.

Две мины на этом пути. Первая — права на файлы во временном каталоге: если .crt лежит с владельцем root, деплой падает с отказом в доступе, и сообщение об этом выглядит совсем не как проблема прав. Вторая — неполная цепочка. verifycrt обязан пройти до deploycrt; если он ругается, класть сертификат бессмысленно, вы просто получите тот же нерабочий keystore, только с новым содержимым.

Если предыдущая попытка деплоя зависла на полпути, помогает убрать в сторону старые файлы хранилища (/opt/zimbra/ssl/zimbra/jetty.pkcs12 и /opt/zimbra/mailboxd/etc/keystore) и передеплоить заново — но копию перед этим сделайте обязательно, иначе откатываться будет не к чему.

Это проверка перед обновлением, а не после. Две минуты сейчас экономят вечер потом. Из-под пользователя zimbra:

zmcontrol -v
zmlocalconfig -s mailboxd_java_options
/opt/zimbra/bin/zmcertmgr viewdeployedcrt | grep -E 'Subject|Issuer|Not After'
ls -la /opt/zimbra/log/*.pid 2>/dev/null | wc -l
find /opt/zimbra -maxdepth 3 -not -user zimbra -not -path '*/log/*' | head

Отдельная строка для тех, кто на девятке. Тот же симптом — mailboxd не поднимает webapps без внятной ошибки — я встретил в 2023 году на Zimbra 9 с патчем P26, и там причина была совсем неожиданная: урезанные права на /tmp для пользователя zimbra, из-за чего конфигурация не могла обновиться. Если вы недавно закручивали гайки по /tmp (noexec, отдельный tmpfs, жёсткие права) — начинайте проверку с этого.

Хронология вечера, по журналу. 18:20 — запуск апгрейда. 19:00 — админ уехал. 20:10 — я подключился. 21:50 — нашёл настоящую причину, потеряв до этого полтора часа в базе. 22:20 — mailboxd поднялся. 00:40 — всплыл keystore. 01:35 — сервер работает целиком, я прогнал контрольную проверку: отправка наружу, приём снаружи, вход в веб-клиент, синхронизация с телефона.

Итог: 7 часов 15 минут простоя почты — от 18:20, когда встала доставка в ящики, до 01:35, когда сервер заработал целиком. Из них 4 часа пришлись на вечер пятницы, когда ещё шли подтверждения записи от страховых, а оставшиеся три с небольшим — на ночь, когда почта клинике всё равно была не нужна. Пятнадцать писем осели в очереди и доехали в ящики после старта mailboxd — не потерялись, что для клиента было главным вопросом.

Что было в цифрах. Ящиков 22, store 96 ГБ, самый большой ящик 14 ГБ у регистратуры. Мои работы за тот вечер — 5 часов 25 минут, счёт 38 000 ₽ с ночным коэффициентом. Через неделю мы отдельным окном перешли на 8.8.15 и заодно навели порядок в java-опциях: 3 часа, спокойно, в воскресенье утром.

Что клиенту стоило бы бездействие. Понедельник у них начинается в 08:00, к 09:30 в регистратуру приходит первая волна пациентов. Без почты не работает выгрузка направлений и подтверждения по ДМС — это в среднем 30–40 приёмов за день, при среднем чеке 3 200 ₽ речь про 96–128 тысяч рублей за день. Плюс репутация: пациент, которому не подтвердили запись, второй раз не звонит.

Три вывода, которые стоят дороже, чем команды выше.

Первое. Симптом «не стартует mailboxd» ничего не говорит о причине. За вечер я прошёл три разные — JVM, PID-файлы, keystore — и каждая давала одинаковую строчку Stopped в zmcontrol status. Диагностика начинается с zmmailboxd.out, потому что это единственный лог, который пишется до того, как приложение вообще запустилось.

Второе. Обновление и смена сертификата — две работы, а не одна. Разводите их по разным окнам, иначе будете в темноте разбирать наложение двух отказов.

Третье, самое неудобное. Апгрейд не сложен технически — сложна неопределённость. Вы не знаете заранее, какая из мин заряжена, и в момент аварии учитесь на живом сервере, под звонки. Именно поэтому вечер пятницы — худшее время: у вас нет ни свежей головы, ни возможности откатиться назад без потерь. Резервная копия /opt/zimbra/conf, /opt/zimbra/data/ldap и снимок виртуальной машины перед стартом обновления стоят двадцать минут и снимают половину рисков.

Если хотите заранее понять, что у вас взорвётся при следующем обновлении, — пришлите мне вывод четырёх команд: zmcontrol -v, zmlocalconfig -s mailboxd_java_options, zmcertmgr viewdeployedcrt и список PID-файлов. Отвечу за день, какие грабли у вас разложены и в каком порядке их убирать.

Почему нельзя просто откатить обновление, если не стартует?

Потому что откатывать в Zimbra по сути нечего: апгрейд переписывает конфигурацию, схему LDAP и структуру базы под новую версию. Единственный настоящий откат — восстановление снимка виртуальной машины или холодной копии, снятой до старта. Если снимка нет, а обновление уже прошло, дорога только вперёд: искать причину и добивать старт. У клиники снимка не было — их админ его не сделал. Поэтому я и разбирал три причины подряд ночью, вместо того чтобы вернуть машину в состояние 18:19 и спокойно спланировать повтор на выходные.

Какой лог смотреть первым, если mailboxd не поднимается?

~zimbra/log/zmmailboxd.out. Это стартовый вывод самой JVM, и он пишется раньше, чем приложение Zimbra успевает открыть свой mailbox.log. Я на этом потерял полтора часа: увидел, что mailbox.log обрывается за минуту до апгрейда, и решил, что процесс падает мгновенно из-за базы. На деле JVM не создавалась вообще — в zmmailboxd.out лежали три строки про нераспознанную опцию и фатальную ошибку. Правило простое: mailbox.log отвечает на вопрос «что случилось внутри работающего приложения», zmmailboxd.out — на вопрос «а оно вообще запустилось».

Откуда в java-опциях берутся параметры, которых новая версия не понимает?

Обычно из ручного тюнинга прошлых лет. Кто-то читал статью про сборщик мусора, добавил флаги CMS и печать GC-меток, это годами работало. Апгрейд приносит другую версию Java, где часть флагов объявлена устаревшей, а часть просто исчезла. Для JVM незнакомый флаг — не предупреждение, а фатальная ошибка: она не стартует. Zimbra формирует значение по умолчанию сама, но если вы когда-то переопределили параметр целиком, обновление ваше переопределение не тронет. Поэтому после каждого мажорного апгрейда сравнивайте mailboxd_java_options с дефолтом новой версии.

Обязательно ли ставить самоподписанный сертификат, чтобы вернуть коммерческий?

Не обязательно, но это самый быстрый способ разделить две проблемы. Пока вы не знаете, сервер не стартует из-за сертификата или из-за чего-то ещё, самоподписанный даёт чистую точку отсчёта: если с ним всё поднялось, дело точно в коммерческом сертификате или в цепочке. У клиники именно так и вышло. Дальше кладёте коммерческий обратно, обязательно с полной цепочкой и обязательно через verifycrt перед deploycrt. И следите за правами на файлы во временном каталоге — сертификат с владельцем root даёт отказ в доступе, а сообщение об этом на проблему прав совсем не похоже.

Мы обновлялись и всё прошло гладко. Значит, у нас этих мин нет?

Значит, на том конкретном переходе они не сработали. Набор ловушек зависит от того, с какой версии на какую вы идёте и что накопилось в конфигурации. Java-опции стреляют при смене версии Java внутри дистрибутива; PID-файлы — когда службы останавливались жёстко; keystore — когда у вас коммерческий сертификат и меняется структура хранилища. Проверка перед следующим окном занимает две минуты: посмотрите java-опции, срок сертификата, наличие PID-файлов при остановленных службах и файлы с владельцем root в дереве Zimbra. Всё, что нашли, чините заранее, а не в разгар обновления.