Привет, Хабр!
Сегодня расскажем не столько о решении — оно оказалось простым – сколько о самом процессе его поиска. Он был настолько увлекательным, что в какой-то момент мы почти уверовали в существование магии. Но мы — инженеры, а поэтому как никто знаем, что чудес не бывает. Поэтому, откинув домыслы и иррациональность, мы шаг за шагом распутывали этот технический узел, докапываясь до первопричины проблемы. Приступим же к нашему расследованию. Приятного чтения!
Пролог: проблема
Внештатная ситуация в системах заказчика. Мы столкнулись с некорректной работой СРК. Спустя непродолжительное время к кейсу подключили экспертную поддержку.
По просьбе заказчика мы на нескольких сотнях виртуальных машин под управлением OS Windows ставим ПО EDR (Endpoint Detection & Response), перезагружаем системы — все работает штатно. Но на паре машин, на которых процесс начался позже, агент системы резервного копирования Tivoli Storage Manager от IBM не стартовал вообще. На этих ВМ мы получили ошибку:
«Вендора нет, сами справимся», — подумали мы и пошли искать корень зла самостоятельно.
Когда к вопросу подключилась экспертная поддержка, коллеги успели:
проанализировать поведение агента TSM через ProcMon;
запустить агент с различными опциями в файле конфигурации dsm.opt;
проанализировать логи Java, TSM, Windows; actlog на стороне сервера TSM; трафик через WireShark;
переустановить агент TSM;
удалить системы EDR и антивирус.
После всего вышеперечисленного стало понятно: при запуске агент устанавливает локальное соединение между своими процессами и затем уже подключается к серверу. Но как раз этих подключений на проблемном сервере мы не увидели. Переустановка агента и удаление систем защиты к результатам не привели.
Гипотеза #1
В первую очередь, конечно же, подозрение пало на антивирусное ПО и EDR. Вендор этих продуктов проанализировал проблему, но ничего не нашел. Полностью откинули эту версию, когда коллеги развернули рядом чистую систему. Но и здесь проблема воспроизводилась. Более того, на рабочей станции в виртуальной машине проблема повторялась, что настораживало сильнее.
Немного технических вводных: один из серверов, на котором не работает агент СРК, был резервной нодой кластера СУБД. Таким образом, в случае переключения на нее нам придется забирать архивные логи вручную, иначе файловая система переполнится и СУБД под критичным сервисом заказчика встанет.
Проблема обрастала мистикой и теориями заговора. А вдруг это тайм-бомба IBM или какой-то истекший сертификат внутри агента TSM? В первую очередь пугали неизвестность и отсутствие обходного пути, потому что, как мы уже сказали, переустановка с нуля проблему не решит.
На случай, если проблема приобретет массовый характер, мы все же подготовили план:
Вдох-выдох… включаем критическое мышление
Отогнав мысли о конспирологии, мы начали упорядочивать факты. Сначала развернули новую ВМ в нашей стендовой системе виртуализации. Агент запустился.
Разница между версиями была только в Windows Server. Развернули аналогичную версию, что и на проблемной машине заказчика, — все продолжило работать. Проделали то же самое на своей рабочей машине — функционирует штатно. Мистика. Созванивались с коллегой, он продемонстрировал проблему, тут же экспортировал данную ВМ и передал нам. Запустили ее у себя, и агент заработал. Без каких-либо изменений.
Понятно одно — проблема за пределами операционной системы. Корень зла либо в виртуализации, либо в аппаратной платформе, конкретнее — в CPU. Это лишь подстегнуло нас — пошли копать дальше.
Догадки и маленький успех
Итак, перед нами — конкретная ошибка сетевого взаимодействия. Откуда она взялась? Изучаем процесс запуска приложения. Агент запускается исполняемым файлом dsm.exe, который стартует Java-приложение. JRE для запуска агента идет в комплекте, поэтому вопрос совместимости с JAVA не стоит. Затем открывается Wizard по настройке агента. После ввода имени хоста и перехода на следующий шаг на проблемных машинах возникает ошибка. Именно в данный момент устанавливается внутреннее подключение. Поэтому перед этим наш Wizard должен запустить какой-то процесс, так как на шаге ввода имени сервера еще ни один процесс не слушает нужный порт. Берем утилиту procmon и при ее помощи находим создание процесса dsmagent.exe:
На рабочей системе появляется подключение к процессу по сети:
На проблемной системе этих подключений не оказалось. Для более глубокого анализа стартуем процесс вручную. Приложение запускается с параметрами, как видно из скрина с утилитой procmon:
dsmagent.exe 0 0 0 0 <путь к временному файлу>
Этот временный файл нулевого размера, поэтому создаем пустой файл test.tmp в директории с агентом. Запускаем — ошибка:
error 03/05/2025 10:49:39 (dsmagent) ANS1035S Options file 'C:\Program Files\Tivoli\TSM\baclient\dsm.opt' could not be found, or it cannot be read.Перезапускаем Wizard и видим, что в процессе он создает пустой dsm.opt. Создаем dsm.opt теперь вручную и перезапускаем dsmagent.exe:
Теперь переходим на проблемную машину. Повторяем процедуру — приложение падает:
Для нас это маленький успех: причина неработоспособности агента крылась именно в этом процессе, что сильно сужает зону поиска.
Продолжение следует
Снимаем дамп через диспетчер задач и открываем в WinDbg.
Из скрина видно: из-за ошибки 0xC0000005 (ACCESS_VIOLATION) на инструкции MOVAPS приложение падает при инициализации библиотеки icclib085.dll. Как правило, это связано с проблемой выравнивания данных в памяти или с доступом к недопустимой области. В логе Windows тоже есть информация о падение процесса с указанием проблем в данной библиотеке.
Отступление автора: Данная библиотека принадлежит пакету Global Security Kit от IBM и отвечает за SSL/TSL. Судя по описанию, в ней содержится много кода от OpenSSL и многие проблемы, как правило, лечатся обновлением. Похоже, наш workaround найден, но корневая проблема остается неизвестной. А вдруг старая версия агента перестанет работать? Возвращаемся к поиску.
Итак, судя по дампу, область памяти, которая копируется в регистр xmm6, принадлежит проблемному процессу. Она доступна для чтения:
0:000> !address 0x000001ED9E3C876C-0x48
Usage: Heap
Base Address: 000001ed`9e3c0000
End Address: 000001ed`9e3e1000
Region Size: 00000000`00021000 ( 132.000 kB)
State: 00001000 MEM_COMMIT
Protect: 00000004 PAGE_READWRITE
Type: 00020000 MEM_PRIVATE
Allocation Base: 000001ed`9e3c0000
Allocation Protect: 00000004 PAGE_READWRITE
More info: heap owning the address: !heap -s -h 0x1ed9d2b0000
More info: heap segment
More info: heap entry containing the address: !heap -x 0x1ed9e3c8724
Content source: 1 (target), length: 188dcПроверяем на выравнивание:
0x000001ED9E3C876C - 0x48 = 0x000001ED9E3C8724
0x000001ED9E3C8724 % 16 = 4 Указатель, используемый в первом вызове MOVAPS, не кратен 16, а значит, гарантированно вызывает 0xC0000005 (ACCESS_VIOLATION). Но что с этим делать дальше?
CPU или не CPU?
«Может, разные процессоры по-разному обрабатывают SSE-инструкции или разные платформы по-разному выравнивают данные?» — думали мы. В какой-то баг процессора верилось мало — больше походило на проблему оптимизации под разные процессы во время сборки. Версия агента не самая актуальная и, возможно, не совместима с новыми поколениями процессоров, хотя ошибка возникала на старых инструкциях из расширения SSE. Мы предположили: если данные расположены в памяти без выравнивания по какой-то ошибке, но они валидны, то есть шанс это исправить.
У инструкции MOVAPS есть аналог — MOVUPS. Она не требует выравнивание памяти, по размеру такая же, поэтому мы можем ее легко заменить без перекомпиляции приложения. Главное отличие — скорость выполнения, MOVUPS медленнее. Итак, пробуем заменить одну инструкцию на другую. Для этого ищем в HEX-редакторе адреса инструкций и меняем 0F 28 -> 0F 10. Открываем библиотеку в Ghidra, проверяем, что все получилось и инструкция сменилась с MOVAPS -> MOVUPS. Идем на стенд.
На рабочей машине без изменений: как работало, так и продолжает работать. А вот проблемное поведение изменилось, но приложение все равно падало уже за пределами библиотеки.
Копать дальше нам показалось малоперспективным. Однако напоследок решили сравнить, что именно находится в памяти перед вызовом MOVAPS на рабочей и проблемной машине. Для этого на системе, где работает агент, запустили dsmagent.exe в x64dbg, чтобы найти адреса инструкций и расставить нужные точки останова. И тут мы увидели: агент на рабочей машине использует другую версию библиотеки:
Вместо icclib085.dll была загружена icclib084.dll. Быстрый поиск показал, что в GSK присутствуют две версии библиотеки и располагаются они по разным путям:
C:\Program Files\Common
Files\Tivoli\TSM\api64\gsk8\lib64\N\icc\icclib\icclib085.dll
C:\Program Files\Common
Files\Tivoli\TSM\api64\gsk8\lib64\C\icc\icclib\icclib084.dll Гипотеза #2
При инициализации GSK на каких-то условиях делается выбор, какую библиотеку загружать. Именно в этом месте скрывается ответ на вопрос, почему на разных платформах разное поведение. К этому моменту наши коллеги провели еще один эксперимент и установили зависимость проблемы от CPU более точно. Создали чистую ВМ, поставили агента и мигрировали ее между разными хостами виртуализации. В итоге проблема проявлялась только на хостах с процессорами Intel IceLake (Intel(R) Xeon(R) Platinum 8358 и Intel(R) Xeon(R) Silver 4316) + на мобильном процессоре Intel Core Ultra 125h.
Но перед долгим исследованием библиотек GSK в голову пришла идея: а что если убрать библиотеку icclib085.dll. Быстро проверили на стенде, — и о чудо! — агент запустился без проблем. Тестовые бэкапы прошли, все работало штатно. Но все же вопросы — а в чем причина, и не может ли это повлиять на работу агента — остались пока на повестке.
Чтобы быстро найти место, где вызывается библиотека, в отладчике ставим точки останова на вызов LoadLibrary. Запускаем выполнение процесса — очередное удивление. Агент на рабочей системе сначала пытается проинициализировать библиотеку icclib085.dll, но функция LoadLibrary возвращает 0, и мы видим ошибку: ERROR_DLL_INIT_FAILED/STATUS_DLL_INIT_FAILED.
Затем мы видим, как перебираются другие пути, загружается библиотека icclib084.dll. После этого агент успешно запускается и работает.
Эпилог, обходные решения и это не конец
В этом месте стоит вернуться к CPU. На новом поколении процессоров могут быть внесены изменения, которые влияют на поведение системы: более строгие проверки доступа к памяти; требования к выравниванию данных и другие улучшения, направленные на повышение безопасности и стабильности работы. В результате вместо простой ошибки при выполнении функции LoadLibrary система выбрасывает исключение и завершает весь процесс целиком.
Таким образом, проблемная библиотека, возможно, никогда не работала корректно. В ней присутствовала скрытая ошибка, которую без доступа к исходному коду исправить крайне сложно. Однако благодаря нашему расследованию мы сформулировали несколько обходных решений:
1. Удалить проблемную библиотеку;
2. Установить предыдущую версию агента;
3. Мигрировать виртуальную машину на хост с другими процессорами;
4. Уменьшить набор инструкций на кластере виртуализации до уровня Cascade Lake при помощи технологии EVC (Enhanced vMotion Compatibility) в VMware для ограничения набора инструкций, доступных виртуальным машинам.
Мы протестировали на стенде последнее решение и получили положительный результат. Согласно документации по EVC от VMware, процессоры поколения Ice Lake добавляют следующие функции:
This EVC mode exposes additional CPU features including SHA extensions,
Vectorized AES, User Mode Instruction Prevention, Read Processor ID, Fast Short
REP MOV, WBNOINVD, Galois Field New Instructions, and AVX512 Integer Fused Multiply Add, Vectorized Bit Manipulation, and Bit Algorithms Instructions.
Очевидно, что одна из этих функций влияет на работу библиотек из GSK и вызывает проблему.
В нашем случае самое правильное решение — перейти на новую версию. Но тут есть свои нюансы, и это совсем другая история. Пока процесс перехода находится в стадии реализации, у нас есть быстрое и эффективное решение существующей проблемы. Более того, проведенный анализ позволил глубже понять принципы работы ПО, что особенно ценно в условиях отсутствия поддержки со стороны вендора.
И в качестве заключения: за простым решением — удалением файла или рекомендацией обновить ПО — стоит огромная работа команды специалистов, десятки часов анализа логов, тестирования и поиска корневой причины. Вы можете сказать, что это и так очевидно. Но задача, согласитесь, любопытная. Еще любопытнее было ее анализировать по-нашему — инженерному. Как вам? Делитесь впечатлениями в комментариях.