Наша команда разрабатывает кроссплатформенное ядро приложений, которое должно собираться на Windows под Visual Studio 2015, Linux с gcc 4.9+, MacOS, iOS, Android и Windows Phone 8.1+. Для автоматической проверки кода на Jenkins настроены сборки под все требуемые конфигурации. Задача сборок отловить код, который не собирается на одной или нескольких из платформ или не проходит юнит-тесты и не дать ему попасть к командам конечных приложений до внесения соответствующих исправлений. Такой процесс CI позволяет разработчику локально использовать удобную ему операционную систему и среду разработки, будь то Visual Studio, XCode, QtCreator или вообще vim + ninja, при этом не бояться, что его изменения не соберутся или будут валить тесты в другом окружении.

В идеальном мире красная сборка на Jenkins (именно он у нас используется в роли билдсервера) говорит о проблеме в коде. Увидев красный свет на висящем в углу комнаты мониторе, «дежурный за сборку» должен пойти и поправить найденную проблему. В реальности же причины падения билда могут быть самыми разными, например, обрыв соединения с нодой, на которой проходила компиляция, закончившееся место на диске или прилёт инопланетян. Такие ложные срабатывания отнимают лишнее время у команды, притупляют внимание и в целом снижают доверие к CI в команде. Историю борьбы с одной из таких проблем я хочу рассказать.

Проблема была специфичная для MSBuild и проявлялась примерно таким сообщением в логе:

20:03:56 "D:\jenkins\workspace\task\ws\...\SomeTarget.vcxproj" (default target) (429) ->
20:03:56 (_QtMetaObjectCompilerH target) -> 
20:03:56 D:\jenkins\workspace\task\ws\...\SomeQtBasedTarget.targets(52,5): error MSB4175: The task factory "XamlTaskFactory" could not be loaded from the assembly "Microsoft.Build.Tasks.Core". Could not find file 'D:\jenkins\workspace\task\ws\TEMP\fv5nnzin.dll'. [D:\jenkins\workspace\jenkins\workspace\task\ws\...\SomeTarget.vcxpro]

Некоторое время проблема проявлялась не часто, раз в несколько дней, и заставляла только чертыхаться и в очередной раз перезапускать упавший билд. Но после переезда с виртуалок на новые блестящие хардварные ноды ситуация усугубилась, рандомные падения могли случаться по несколько раз на дню. Делало ситуацию окончательно неприемлемой и долгое время сборки проекта (десятки минут, с которым мы, к слову, вели борьбу параллельно). Иногда нужно было прогнать срочный фикс через CI, но прождав кучу времени можно было словить падение, и тогда приходилось ждать заново.

Итак, что же всё-таки приводило к ошибке?

Для генерации проектов мы используем gyp, в котором есть 2 способа вызвать внешнюю команду во время сборки — это actions и rules. Actions реализованы через CustomBuild внутри vcxproj-файлов.

Пример из документации:

<ItemGroup>
  <CustomBuild Include="faq.txt">
    <Message>Copying readme...</Message>
    <Command>copy %(Identity) $(OutDir)%(Identity)</Command>
    <Outputs>$(OutDir)%(Identity)</Outputs>
  </CustomBuild>
</ItemGroup>

И с ними всё хорошо, они не взрываются. Rules же используют другой механизм. Комментарий в коде гласит:
MSBuild rules are implemented using three files: an XML file, a .targets file and a .props file. See blogs.msdn.com/b/vcblog/archive/2010/04/21/quick-help-on-vs2010-custom-build-rule.aspx.

Как это работает? Для каждого такого правила MSbuild в %TEMP% генерирует исходник на C# (.cs-файл), из которого пытается скомпилировать dll-ку и тут же её заиспользовать, а если это не получилось, кидает исключение.
В комментарии написано:
This occurs if there is a failure to compile the assembly. We just pass through because we will take care of the failure below.

И действительно, в системном журнале за пару секунд до времени ошибки (по логу билдсервера) можно обнаружить примерно такую запись об ошибке компилятора C#:

Faulting application name: csc.exe, version: 4.6.1055.0, time stamp: 0x563c1a09
Faulting module name: KERNELBASE.dll, version: 6.3.9600.18233, time stamp: 0x56bb4ebb
Exception code: 0xc0000142
Fault offset: 0x00000000000ecdd0
Faulting process id: 0x1af4
Faulting application start time: 0x01d1d13dbec0f5bd
Faulting application path: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\csc.exe
Faulting module path: KERNELBASE.dll
Report Id: fc6cf36d-3d30-11e6-8260-0cc47ab21249
Faulting package full name: 
Faulting package-relative application ID:

Поиск похожих ошибок в Гугле навёл на мысль, что дело в размере Desktop Heap для не интерактивных сессий. Действительно, было похоже на то: совпадал код ошибки, а Jenkins slave agent работал в виде службы Windows.

Взяв в разработку эту гипотезу, я стал играться со значением секции SharedSection в записи реестра HKEY_LOCAL_MACHINE\System\CurrentControlSet\Control\Session Manager\SubSystems\Windows. Попутно мне случайно удалось сделать сборку подверженную падению почти со 100% вероятностью, что несколько облегчило итерации отладки. Почитав ещё немного я добрался до галочки «Разрешить взаимодействие с рабочим столом» в свойствах службы Jenkins, а затем и до опции NoInteractiveServices в HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Windows. Но плодов все эти попытки не принесли. Иногда билды проходили, но уловить закономерности не удавалось.

Продолжая ковыряться с особенностями запуска процессов из-под службы Jenkins, я набрёл на следующий текст на StackOverflow. Автор говорит об особенностях дефолтного поведения MSBuild при указании ему опции /M для параллельной сборки нескольких проектов. Суть в том, что MSBuild создаёт нужное число своих копий — нод, ожидающих задач. В процессе сборки задачи раскидываются на эти ноды и выполняются параллельно. После завершения сборки ноды не гасятся и продолжают ожидать поступления новых задач. Так происходило и у нас на Jenkins, после окончания сборки процессы MSBuild продолжали висеть в памяти.

Я начал экспериментировать. Воспроизведя падение билда несколько раз подряд я убил все висевшие в памяти процессы MSBuild, и, о чудо, следующий билд прошёл успешно! Тогда я вооружился инструкцией со StackOverflow и добавил в наш билдскрипт выставление переменной MSBUILDDISABLENODEREUSE и проброс опции /nr:false в вызов MSBuild. После этого все процессы MSBuild стали умирать в конце сборки, а не оставались висеть в памяти.

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

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


  1. alexkran
    05.08.2016 03:47

    Интересно было почитать, спасибо.

    Такие статьи хорошенько заряжают энергией, аж захотелось в своем проекте пару багов закрыть.

    А если говорить по теме: у MSBuild всегда были проблемы с выделением и распределением ресурсов.


  1. vivlav
    05.08.2016 06:39

    Тоже наткнулись на это, но предварительно так и не разобрались (падала примерно каждая третья), подумали, что глючит MsBuild и отключили параллельную сборку, время выросло, но не фатально для нас.


  1. AndreyDmitriev
    05.08.2016 09:34

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


    1. Un1oR
      05.08.2016 10:05

      %TEMP% мы переопределяем, чтобы не дёргать системный диск лишний раз (на виртуалках это ещё было и заметно медленнее), и он грохается целиком вместе с воркспейсом в конце сборки.


  1. Ogoun
    05.08.2016 20:23

    Галочка «Разрешить взаимодействие с рабочим столом» оставлена только для совместимости, на всех Windows выше XP ее установка ни к чему не приводит. Сделано в рамках усиления безопасности. Например, чтобы службы не могли перехватывать клавиатуру пользователя. Как еще одно из проявлений этого — службы не могут пихать значки в трей и показывать окошки с уведомлениями, могут делать это только через интерактивные приложения-посредники.


    1. Un1oR
      06.08.2016 07:08

      Да, про это я прочитал чуть позже, чем нашёл опцию. Насколько я понял, она работает, но только при взведённой NoInteractiveServices в 0. В любом случае, это всё оказалось неважным, и решение было в другом.