Для получения триального ключа
заполните форму ниже
Team License (базовая версия)
Enterprise License (расширенная версия)
* Нажимая на кнопку, вы даете согласие на обработку
своих персональных данных. См. Политику конфиденциальности

Запросите информацию о ценах
Новая лицензия
Продление лицензии
--Выберите валюту--
USD
EUR
GBP
RUB
* Нажимая на кнопку, вы даете согласие на обработку
своих персональных данных. См. Политику конфиденциальности

Бесплатная лицензия PVS-Studio для специалистов Microsoft MVP
* Нажимая на кнопку, вы даете согласие на обработку
своих персональных данных. См. Политику конфиденциальности

Для получения лицензии для вашего открытого
проекта заполните, пожалуйста, эту форму
* Нажимая на кнопку, вы даете согласие на обработку
своих персональных данных. См. Политику конфиденциальности

Мне интересно попробовать плагин на:
* Нажимая на кнопку, вы даете согласие на обработку
своих персональных данных. См. Политику конфиденциальности

Ваше сообщение отправлено.

Мы ответим вам на


Если вы так и не получили ответ, пожалуйста, проверьте папку
Spam/Junk и нажмите на письме кнопку "Не спам".
Так Вы не пропустите ответы от нашей команды.

>
>
Когда дворецкий - жертва

Когда дворецкий - жертва

07 Дек 2017

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

0546_When_a_Butler_Becomes_a_Victim_ru/image1.png

Введение

Вначале - немного теории. Мы разрабатываем PVS-Studio - статический анализатор кода для C, C++ и C#. Для внутреннего тестирования нашего продукта мы используем разнообразные инструменты и приёмы: Unit и UI-тесты Visual Studio, совместный обзор кода, специализированные приложения-тестеры. Остановлюсь более подробно на последнем пункте.

При разработке новых диагностических правил, а также при изменении внутренних механизмов анализатора, всегда необходимо понимать, как именно произведенные изменения отразились на качестве анализа. Для решения данной задачи мы выполняем тестовые прогоны анализатора на некотором наборе больших открытых проектов. Для С/C++ кода используется около 150 проектов, для C# - 52. Тестер для анализа C/C++ проектов в Windows называется SelfTester. Далее речь пойдет именно про этот инструмент. Также существует специализированная система для Linux, но сейчас она останется за кадром.

Вся работа производится на сборочном сервере с Windows 10. В качестве сборочной системы мы используем Jenkins, который настроен на регулярный ночной запуск, в том числе, и тестеров. Запуск самого Jenkins производится из cmd-файла командой:

java -jar jenkins.war >
%JENKINS_PROJECTS%\Logs\%YYYY%.%MM%.%DD%_%HH%.%MI%.log 2>&1

Переменная JENKINS_PROJECTS задает местоположение папки проектов Jenkins на локальном диске. Переменные YYYY, MM, DD, HH и MI содержат, соответственно, дату и время на момент выполнения. Таким образом, после запуска Jenkins вывод его консоли будет перенаправлен в файл с именем вида:

2017.11.08_17.58.log

Cmd-файл стартует при помощи планировщика задач Windows. Запуск Jenkins как службы Windows для нас оказался неприменим, так как в этом случае возникали проблемы в работе UI-тестов Visual Studio: у службы нет рабочего стола. Таким образом, цепочка запусков выглядит так:

Windows Task Manager -> cmd.exe -> java.exe

Итак, ознакомившись с краткой вводной, перейдем к вопросу о том, что же пошло не так.

Проблема

Около полугода назад мы стали замечать, что время от времени Jenkins закрывается во время ночных сборок. В результате его приходилось запускать вручную, проверять логи и перезапускать некоторые задачи. Проблема воспроизводилась достаточно регулярно. Расследование было решено начать с более пристального изучения поведения Jenkins, ведь это именно он выполняет всю "грязную работу" и первым попадает под подозрение. Да-да, тот самый дворецкий.

Jenkins

В первую очередь была проверена конфигурация и настройки задач Jenkins. Проверка не выявила ничего серьезного. Тем более, если бы была допущена ошибка, например, в очередности, приоритете или времени запуска задач, то проблема, вероятно, проявлялась бы иначе. Да и маловероятно, чтобы Jenkins падал вследствие ошибок конфигурации.

В качестве временной меры задача планировщика Windows была перенастроена на периодический запуск Jenkins каждые 30 минут. Для защиты от повторного запуска выполнялась проверка наличия уже запущенного процесса.

Следующий шаг - изучение логов консоли Jenkins. Как вы, наверное, помните, у нас они сохраняются в папку %JENKINS_PROJECTS%\Logs, а имена файлов содержат метку времени создания (фактически - времени перезапуска Jenkins). Через какое-то время мы изучили содержимое этой папки и, как и ожидалось, обнаружили там довольно большое число файлов. Это свидетельствовало о том, что Jenkins продолжает перезапускаться. При этом сами логи консоли Jenkins не содержали ничего криминального. А проблема приобрела несколько иной характер: часть ночных тестов перестала выполняться. Они просто не стартовали. А те, что стартовали, зачастую завершались с ошибками.

Все это говорило в пользу того, что сам Jenkins, вероятно, не виноват. Кто-то извне препятствует его работе, "убивая" процесс java.exe.

0546_When_a_Butler_Becomes_a_Victim_ru/image2.png

Windows

В качестве следующего подозреваемого была выбрана Windows. Ну действительно, кому как не операционной системе нести ответственность за незапланированное завершение процессов. Возможно, система перезагружается после установки обновлений, либо по какой-то причине закрывает только процесс java.exe. Такое возможно, когда кто-то препятствует рестарту и он не производится, но система уже успела убить часть процессов. Так или иначе, но проведенный анализ логов Windows не дал результатов. Да, иногда система действительно перезагружалась, но все происходило в штатном режиме. Да и время и место "преступления" не совпадали.

Примерно в то же время, когда мы проводили наше расследование, случилось еще одно происшествие, которому сразу не было придано большого значения. В одну из ночей наш сборочный сервер "упал" вследствие возникновения BSOD. Автоматическая перезагрузка не случилась, поэтому утром мы могли лицезреть весьма безрадостную картину.

Для анализа дампа памяти был использован Windows Debugger (WinDbg). Утилита нашлась по пути "C:\Program Files (x86)\Windows Kits\10\Debuggers\x64\windbg.exe". Дамп находился по стандартному пути "C:\Windows\MEMORY.DMP". После анализа дампа в WinDbg была обнаружена причина и виновник BSOD:

CRITICAL_PROCESS_DIED (ef)
CRITICAL_PROCESS:  svchost.exe
....
FAILURE_BUCKET_ID:
0xEF_svchost.exe_BUGCHECK_CRITICAL_PROCESS_TERMINATED_BY_
SelfTester.exe_6771c7c0

Как вы понимаете, принудительное закрытие экземпляров процессов svchost.exe обычно приводит к BSOD. Можете проверить.

Да, наш безукоризненный инструмент SelfTester привел к краху Windows. Но так как это было первое подобное происшествие за всю многолетнюю историю существования тестера, а последние правки в его код вносились очень давно, было решено считать, что "нам показалось".

Тем временем, расследование шло своим чередом. Для выяснения виновника завершения процесса java.exe была использована штатная Windows-утилита для настройки ключей реестра "Global Flags". В числе прочего она позволяет задать режим мониторинга завершения указанного процесса с записью события в системный лог:

0546_When_a_Butler_Becomes_a_Victim_ru/image3.png

В случае принудительного завершения процесса сторонним процессом, Application лог Windows должен содержать событие с Event ID = 3001 от источника Process Exit Monitor.

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

Наконец, в одно прекрасное утро проблема повторилась, а в системном логе появилась следующая запись:

The process 'C:\Program Files\java\jre1.8.0_102\bin\java.exe' was terminated by the process 'D:\SelfTester\SelfTester.exe' with termination code 0. The creation time for the exiting process was 0x01d3541edc4f867b.

Снова SelfTester. Получается, именно по его вине завершался процесс java.exe, который его и порождал. Невероятное коварство.

0546_When_a_Butler_Becomes_a_Victim_ru/image4.png

SelfTester

Найти виновника - только половина дела. Теперь следует понять, что именно происходит и как это можно исправить. Для этого разберемся в механизмах работы тестера.

Для анализа каждого проекта С++ тестер запускает процесс анализатора (PVS-Studio_cmd.exe) с параметрами. По завершению анализа тестер не ждёт непосредственно завершения процесса, а реагирует на событие о том, что отчет о проверке (plog) создан, после чего, "на всякий случай", завершает процесс анализатора и его дочерние процессы. Вероятно, именно в этот момент происходит что-то непредвиденное.

На самом деле, этот алгоритм работы является наследием прошлого и сейчас в нем уже нет такой необходимости. Ранее же для анализа запускался devenv.exe c параметрами. Проверку осуществлял плагин PVS-Studio для Visual Studio. В ходе этого порождалось множество дочерних процессов, которые и надо было завершать.

Чтобы понять, что именно происходит, потребовалось добавить логирование механизма завершения процессов. После изучения логов удалось выяснить следующее. Дочерние для PVS-Studio_cmd.exe процессы в тестере ищутся следующим запросом WMI:

SELECT * FROM Win32_Process WHERE ParentProcessId={0}

Проблема в том, что на момент выполнения данного запроса процесса может уже не быть. Он честно отработал и завершился, но тестер этого не знает. Иногда возникает ситуация, когда ID процесса совпадает (был заново использован) с процессом, который изначально породил cmd.exe, на которой висит java.exe (процесс Task Scheduler). При этом Windows помнит ID родительских процессов, даже если они уже завершились. Так мы получаем этот cmd.exe и завершаем его, а также и его дочерние процессы (рекурсивно).

0546_When_a_Butler_Becomes_a_Victim_ru/image5.png

Решение

Проблема была решена добавлением в код тестера двух условий, при которых нельзя завершать дочерние процессы:

  • Родительский процесс уже завершился.
  • Родительский процесс не завершился, но он стартовал позже, чем его предполагаемые дочерние. В этом случае он мог заново использовать ID уже завершившегося процесса.

Заключение

Итак, расследование завершено. Все подозрения с невиновных сняты, а виновные найдены и строго наказаны (исправлены).

В заключение хочу отметить, что описанная ситуация - это, на мой взгляд, хороший пример того, как даже небольшая оплошность может привести к трудно воспроизводимой ошибке.

Мы не стесняемся признать свои ошибки и, думаю, читателям было интересно познакомиться с одной из них.

Безбажного кода и успешных сборок!

Популярные статьи по теме
Главный вопрос программирования, рефакторинга и всего такого

Дата: 14 Апр 2016

Автор: Андрей Карпов

Вы угадали, ответ - "42". Здесь приводится 42 рекомендации по программированию, которые помогут избежать множества ошибок, сэкономить время и нервы. Автором рекомендаций выступает Андрей Карпов - тех…
PVS-Studio для Java

Дата: 17 Янв 2019

Автор: Андрей Карпов

В седьмой версии статического анализатора PVS-Studio мы добавили поддержку языка Java. Пришло время немного рассказать, как мы начинали делать поддержку языка Java, что у нас получилось и какие дальн…
Как PVS-Studio оказался внимательнее, чем три с половиной программиста

Дата: 22 Окт 2018

Автор: Андрей Карпов

PVS-Studio, как и другие статические анализаторы кода, часто выдаёт ложные срабатывания. Но не стоит спешить считать странные срабатывания ложными. Это короткая история о том, как PVS-Studio вновь ок…
Как и почему статические анализаторы борются с ложными срабатываниями

Дата: 20 Мар 2017

Автор: Андрей Карпов

В своей предыдущей статье я писал, что мне не нравится подход, при котором статические анализаторы кода оцениваются с помощью синтетических тестов. В статье приводился пример, воспринимаемый анализат…
Бесплатный PVS-Studio для тех, кто развивает открытые проекты

Дата: 22 Дек 2018

Автор: Андрей Карпов

В канун празднования нового 2019 года команда PVS-Studio решила сделать приятный подарок всем контрибьюторам open-source проектов, хостящихся на GitHub, GitLab или Bitbucket. Им предоставляется возмо…
Характеристики анализатора PVS-Studio на примере EFL Core Libraries, 10-15% ложных срабатываний

Дата: 31 Июл 2017

Автор: Андрей Карпов

После большой статьи про проверку операционной системы Tizen мне было задано много вопросов о проценте ложных срабатываний и о плотности ошибок (сколько ошибок PVS-Studio выявляет на 1000 строк кода)…
PVS-Studio ROI

Дата: 30 Янв 2019

Автор: Андрей Карпов

Время от времени нам задают вопрос, какую пользу в денежном эквиваленте получит компания от использования анализатора PVS-Studio. Мы решили оформить ответ в виде статьи и привести таблицы, которые по…
Статический анализ как часть процесса разработки Unreal Engine

Дата: 27 Июн 2017

Автор: Андрей Карпов

Проект Unreal Engine развивается - добавляется новый код и изменятся уже написанный. Неизбежное следствие развития проекта - появление в коде новых ошибок, которые желательно выявлять как можно раньш…
Любите статический анализ кода!

Дата: 16 Окт 2017

Автор: Андрей Карпов

Я в шоке от возможностей статического анализа кода, хотя сам участвую в разработке инструмента PVS-Studio. На днях я был искренне удивлён тому, что анализатор оказался умнее и внимательнее меня.
Технологии, используемые в анализаторе кода PVS-Studio для поиска ошибок и потенциальных уязвимостей

Дата: 21 Ноя 2018

Автор: Андрей Карпов

Краткое описание технологий, используемых в инструменте PVS-Studio, которые позволяют эффективно обнаруживать большое количество паттернов ошибок и потенциальных уязвимостей. Статья описывает реализа…

Комментарии (0)

Следующие комментарии
Этот сайт использует куки и другие технологии, чтобы предоставить вам более персонализированный опыт. Продолжая просмотр страниц нашего веб-сайта, вы принимаете условия использования этих файлов. Если вы не хотите, чтобы ваши данные обрабатывались, пожалуйста, покиньте данный сайт. Подробнее →
Принять