Пять багов за один вечер и охота за исчезающей задачей планировщика

от

Это не заказ клиента - свой собственный проект автоматизации. Для обкатки новой версии системы я отобрал 13 Windows RDP-серверов из тех, что администрирую - не потому что их всего 13 в управлении, а потому что для пилота нужен был контролируемый, обозримый кусок инфраструктуры. На каждом стоит DigitalRuby.IPBan (сервис, банящий IP по подозрительным логинам), а вся клиентская автоматизация вокруг него написана на PowerShell.

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

Отдельно - вопрос, который тут напрашивается сам собой: зачем вообще выставлять RDP наружу, разве не правильнее спрятать его за VPN. Правильнее, и там, где это возможно, я так и делаю. Но ситуации бывают разные: у части серверов, с которыми приходится работать, RDP и SSH открыты наружу без VPN и без другого канала доступа - так исторически сложилось у конкретных клиентов, и это не всегда в моей власти поменять одним решением. Для таких случаев автоматический бан по факту атаки - реалистичная мера защиты, а не идеальная, но ощутимо лучше, чем ничего.

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

Инсталлятор был написан и вычитан, но ни разу не прогонялся на реальной Windows-машине с живым IPBan. Первый прогон стоит делать осторожно - и вот ровно поэтому: за один вечер на первом же сервере флота (назову его SRV-01) вскрылось пять независимых, реальных багов.

Пять багов PowerShell-инсталлятора за вечер

1. Неподписанный скрипт блокируется политикой выполнения PowerShell.

.\Install-IPBanClient-SRV-01.ps1 : Не удается загрузить файл ... Файл ... не имеет цифровой подписи.
PSSecurityException / UnauthorizedAccess

Не баг - штатная защита Windows на файлах, скачанных из браузера (пометка Zone.Identifier). Фикс:

Unblock-File .\Install-IPBanClient-SRV-01.ps1
Set-ExecutionPolicy -Scope Process -ExecutionPolicy Bypass -Force

2. auditpol падает на нелокализованной под русский Windows подкатегории.

Ошибка 0x00000057 произошла: Параметр задан неверно.

auditpol /set /subcategory:"Logon" использует английское имя подкатегории, которое не распознаётся на ru-RU Windows. Фикс - локале-независимый GUID вместо имени: {0CCE9215-69AE-11D9-BED3-505054503030}. Отдельно всплыл второй, тихий баг рядом: скрипт печатал «OK» в этом месте вне зависимости от реального кода возврата - ложноположительный результат на самом же провале. Поправил в том же заходе.

3. AppendChild у «строки» - пустой XML-элемент схлопывается под точечным доступом PowerShell.

Сбой вызова метода из-за отсутствия в [System.String] метода с именем "AppendChild".
MethodNotFound

Когда <appSettings> в конфиге IPBan полностью пуст (<appSettings></appSettings>, без единого дочернего <add> - именно такое реальное состояние было на SRV-01), точечный доступ PowerShell ($xml.configuration.appSettings) тихо схлопывает пустой элемент в обычную строку вместо XML-узла - и вызов .AppendChild() на этой «строке» падает с ошибкой поиска метода. Корневая причина того, что сервис оставался остановленным посреди установки. Фикс - переписать весь код слияния конфига на настоящие DOM-методы (SelectSingleNode) вместо удобного, но небезопасного для пустых элементов точечного доступа. Сам файл при этом не пострадал ($xml.Save() до сбоя не доходил), но сервис IPBAN оставался остановленным - что требовало немедленного ручного Start-Service IPBAN раньше, чем что-либо ещё.

4. Самому себе заблокировал RDP перезапуском сервиса.

Следующий же прогон инсталлятора (уже после фиксов 2-3) вызвал живую блокировку доступа: «мягкое обновление» со стоп/старт IPBAN заново применяло к файрволу каждый локально закэшированный бан при рестарте (это осознанный выбор - ClearBannedIPAddressesOnRestart=false, чтобы не терять историю банов между апгрейдами) - а собственный текущий IP администратора уже оказался в этом локальном списке банов (случайный неудачный логин, обрыв сессии, что угодно), и не попадал под белый список, засеянный для этого клиента. Первым делом занялся именно блокировкой, доработку отложил - ситуация серьёзная. План восстановления вне полосы: доступ через консоль/IPMI, Get-NetFirewallRule -DisplayName "IPBan_*" | Remove-NetFirewallRule, Stop-Service IPBAN, не перезапускать сервис, пока реальный IP не окажется в белом списке.

Хороший сюжетный поворот для рассказа: инструмент безопасности собственным рестартом вживую блокирует того, кто им управляет, прямо посреди развёртывания.

5. [TimeSpan]::MaxValue переполняет собственную XML-схему планировщика заданий.

Register-ScheduledTask : XML-код задачи содержит значение в неправильном формате или за пределами допустимого диапазона.
(8,42):Duration:P99999999DT23H59M59S
HRESULT 0x80041318

Задача синхронизации раз в 5 минут использовала триггер -Once с -RepetitionDuration ([TimeSpan]::MaxValue), чтобы повторяться «вечно» - но это сериализуется в строку ISO-8601 длительности, которая переполняет то, что принимает схема планировщика. Фикс - вообще убрать -RepetitionDuration: триггер -Once с одним лишь -RepetitionInterval и так повторяется бесконечно сам по себе, без явного указания «вечности».

6. Пропущенная $(...) проглатывает половину URL при интерполяции строки.

URI IS: [=stats]
Invoke-RestMethod : Недопустимый URI: Невозможно выполнить разбор имени хоста.
UriFormatException

"$CentralServerUrl?action=stats" - голое имя переменной, сразу за которым идёт ? - схлопывается парсером интерполяции PowerShell, обрезая всю строку до "=stats". В боевом скрипте синхронизации этот же вызов был написан правильно, с явным синтаксисом подвыражения: "$($cfg.centralServerUrl)?action=..." - а вот именно в собственном финальном самотесте инсталлятора эта одна строка была написана невнимательно. Подтвердил живьём, попросив прогнать точно такую же интерполяцию в изоляции на реальной машине - маленький, воспроизводимый пример на настоящем железе вместо гадания по документации.

7. Гонка блокировки файла в Copy-Item сразу после Stop-Service.

Copy-Item : Процесс не может получить доступ к файлу "C:\ipb\DigitalRuby.IPBan.exe", так как этот файл используется другим процессом.
System.IO.IOException

Get-Service рапортует Stopped на мгновение раньше, чем Windows реально освобождает файловый хэндл процесса. Фикс - вспомогательная функция Copy-ItemWithRetry (до 10 попыток с паузой 2 секунды), которую пришлось продублировать ещё и в отдельный heredoc-скрипт обновления - он выполняется в отдельной области видимости.

Задача, которая исчезала: пять гипотез, ни одна не была ответом, пока не нашлась настоящая

Дальше пошла самая насыщенная отладочная история за весь проект - один и тот же симптом («задача ‘IPBan daily update’ пропадает после однократной успешной работы») потребовал пяти разных, каждая по-своему реальной, причин, прежде чем нашёлся настоящий фикс.

Симптом: клиент, который накануне чисто установился, на следующий день не имел вообще никакой задачи «IPBan daily update» - не старой версии, не сломанной, а полностью отсутствующей: «вообще нет задачи».

Гипотеза 1 - Start-Process подвисает посреди самообновления, оставляя сирот. Ревью кода нашло: $proc.Kill() (вызывается, если самообновляющийся Start-Process превышает 10-минутный таймаут WaitForExit) убивает только один процесс powershell.exe, но не его дочерние процессы (sc.exe, auditpol, вложенный powershell.exe для регистрации задачи) - они становятся сиротами, которые могут продолжать менять состояние системы уже после «убийства» родителя. Реальный баг, исправлен: taskkill.exe /PID $proc.Id /T /F (убить всё дерево процессов целиком), плюс защитный повторный $proc.WaitForExit() без аргументов перед чтением .ExitCode.

Гипотеза 2 - Unregister/Register не атомарны, зависание посреди замены теряет задачу навсегда. Логика: самообновление всегда делает Unregister-ScheduledTask, потом Register-ScheduledTask; если между этими двумя вызовами что-то умерло, задача исчезает без единого шанса на повторную попытку - курица и яйцо, ведь именно та задача, которая должна была бы всё починить, уже не существует. Попытка фикса - переключиться на Register-ScheduledTask -Force, который по документации перезаписывает существующую задачу атомарно, без предварительного удаления.

Этот фикс сломал другого, ранее полностью исправного клиента:

==> Registering scheduled task 'IPBan sync_from_central'
!!  Register-ScheduledTask did not report an error but the task isn't there - register it manually
==> Registering scheduled task 'IPBan daily update'
!!  Could not register the daily update task: Параметр задан неверно.

-Force оказался ненадёжным именно на этой сборке Windows - тот же класс ошибки 0x80070057 / «параметр задан неверно», что уже встречался с auditpol. Откатился обратно на Unregister + Register.

Гипотеза 3 - Kaspersky Endpoint Security блокирует запись в планировщик заданий. Симптом: сам Restart-Service Schedule падал с «не удалось открыть службу Schedule» - отказано в доступе даже к хэндлу службы, от имени администратора. Kaspersky Endpoint Security известен тем, что тихо блокирует изменение служб/планировщика «недоверенными» скриптами как эвристику от закрепления в системе, а на этом флоте уже стоял клиент Kaspersky Security Center - похоже на централизованную политику. Полностью отключил антивирус и повторил - точно та же ошибка, и на этот раз на диске вообще не было ни одного файла IPBan* до самого сбоя, что полностью исключило Kaspersky: конфликт был не на уровне файловой системы.

Гипотеза 4 (подтвердилась, но это симптом, а не корень) - повреждённый реестровый кэш планировщика (TaskCache). При отсутствии файлов на диске, но при том что Register-ScheduledTask всё равно настаивал на существовании имени, диагностика ушла в реестр:

Get-ChildItem "HKLM:\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Schedule\TaskCache\Tree" | Where-Object { $_.PSChildName -like "IPBan*" }

Реестр действительно ещё показывал все три задачи с настоящими GUID - подтверждение, что внутренний индекс планировщика устарел относительно диска. Попытка почистить его напрямую упёрлась в стену - TaskCache защищён на уровне TrustedInstaller, а не просто администратора:

Remove-Item : Запрошенный доступ к реестру запрещен.
System.Security.SecurityException

Рекомендованный фикс именно для этой машины - перезагрузка (планировщик заданий сверяет TaskCache с реальными файлами на диске при старте службы, это задокументированное штатное поведение - безопаснее, чем вручную редактировать ключи реестра, принадлежащие TrustedInstaller, на живой системе).

Гипотеза 5 (подтвердилась через веб-поиск, реальная и независимая) - парсинг времени, зависящий от локали. На другой, свежеперезагруженной машине без какой-либо истории в реестре та же картина повторилась: пятиминутная задача синхронизации регистрировалась нормально, а обе ежедневные задачи («daily update», «metrics collect») стабильно падали. Отличие: у рабочей задачи был триггер -Once, а у падающих - -Daily -At "3:00AM", строка, которую New-ScheduledTaskTrigger парсит через текущую культуру машины, а ru-RU форматирует AM/PM иначе. Фикс - передавать настоящий объект [DateTime] вместо строки:

New-ScheduledTaskTrigger -Daily -At (Get-Date -Hour 3 -Minute 0 -Second 0)

Никакого зависящего от локали разбора строк.

Этот фикс не закрыл проблему до конца - «daily update» по-прежнему падала с той же самой «параметр задан неверно». Веб-поиск (запросы вида Register-ScheduledTask "the parameter is incorrect" 0x80070057 RunLevel Highest ServiceAccount) нашёл задокументированный баг в модуле ScheduledTasks самого PowerShell: комбинация New-ScheduledTaskPrincipal -UserId "SYSTEM" -RunLevel Highest сама по себе бросает ERROR_INVALID_PARAMETER - а RunLevel Highest - это концепция повышения через UAC, которая для учётной записи SYSTEM бессмысленна (она и так максимально привилегирована). Фикс - просто убрать -RunLevel Highest.

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

!!  Could not register the scheduled task: Невозможно создать файл, так как он уже существует.

(«Невозможно создать файл, так как он уже существует» - даже для задачи, которая чисто зарегистрировалась 13 минутами раньше на этой же машине). Это и была разгадка: дело было не в параметрах конкретной задачи, раз даже беспараметрический случай теперь падал. Диагноз: это гонка (race condition) - Unregister-ScheduledTask возвращает управление до того, как служба планировщика реально успевает зафиксировать удаление, и следующий за ним Register-ScheduledTask натыкается на ещё не до конца удалённую старую запись. Это же задним числом объяснило и повреждённый TaskCache на прошлой машине: повторные неудачные попытки регистрации (в погоне за четырьмя другими багами) сами по себе тихо копили мусор в реестре.

Финальный фикс - Register-IPBanTask, хелпер, который после Unregister опрашивает Get-ScheduledTask (до 15 секунд), пока старая задача реально не исчезнет, и только потом вызывает Register, с до 5 повторов, если задержка больше:

function Register-IPBanTask {
    param([string]$TaskName, $Action, $Trigger, $Settings, $Principal, [int]$MaxAttempts = 5, [int]$RetryDelaySeconds = 3)
    Unregister-ScheduledTask -TaskName $TaskName -Confirm:$false -ErrorAction SilentlyContinue
    $waited = 0
    while ((Get-ScheduledTask -TaskName $TaskName -ErrorAction SilentlyContinue) -and $waited -lt 15) {
        Start-Sleep -Seconds 1; $waited++
    }
    for ($i = 1; $i -le $MaxAttempts; $i++) {
        try {
            Register-ScheduledTask -TaskName $TaskName -Action $Action -Trigger $Trigger -Settings $Settings -Principal $Principal -ErrorAction Stop | Out-Null
            if (Get-ScheduledTask -TaskName $TaskName -ErrorAction SilentlyContinue) { return $true }
        } catch {
            if ($i -eq $MaxAttempts) { Write-Warn2 "..."; return $false }
        }
        Start-Sleep -Seconds $RetryDelaySeconds
        Unregister-ScheduledTask -TaskName $TaskName -Confirm:$false -ErrorAction SilentlyContinue
    }
    Write-Warn2 "..."; return $false
}

Все три регистрации задач переключил на вызов этого единственного хелпера вместо дублированной инлайн-логики. Номер версии скриптов дошёл до 12 к концу этой истории (начиналось всё примерно с 7 в начале главы про планировщик).

Итог

Пять независимых, каждый настоящий баг (убийство дерева процессов, ненадёжный на этой сборке Windows флаг атомарной перезаписи, ложный след с антивирусом, который стоил реального времени на диагностику, прежде чем был честно исключён чистым тестом, ловушка с парсингом строки времени по локали, задокументированный баг Microsoft, найденный только через веб-поиск, и, наконец, настоящая гонка unregister/register) - все проявлялись через один и тот же поверхностный симптом («задачи нет»). Каждый фикс был реальным и стоил того, чтобы остаться в коде, но ни один из первых четырёх не был «тем самым» багом.

Выводы

  1. Один и тот же симптом может иметь пять разных, независимо реальных причин одновременно. «Задача исчезла» была правдой пять раз подряд, и все пять объяснений были верны - просто не полны.
  2. «Исправлено» нуждается в проверке на свежей, ранее не тронутой машине, прежде чем объявлять победу - без этого легко принять решение одной из промежуточных гипотез за финальный фикс.
  3. Ложный след стоит диагностировать до конца, а не просто «на всякий случай» исключать. Отключение антивируса и повтор с тем же результатом на машине без единого файла на диске - куда более сильное доказательство, чем «ну, наверное, не антивирус».
  4. Флаги вроде -Force, документированные как атомарные, могут вести себя иначе на конкретной сборке ОС - стоит быть готовым откатить «более правильное по документации» решение, если оно ломает то, что раньше работало.
  5. Гонки между «команда вернула управление» и «система реально зафиксировала изменение» - частый источник неуловимых багов в скриптах, управляющих состоянием ОС (реестр, службы, планировщик) - активное ожидание с опросом состояния часто надёжнее, чем считать операцию завершённой по коду возврата.

Отдельная мысль на будущее: систему можно было бы оформить в отдельный SaaS-продукт для тех, у кого похожая проблема с флотом RDP-серверов под атаками - но пока не проверял, есть ли на это реальный спрос.

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

Оставьте комментарий