Обмен 1С с внешним сервисом падает по таймауту: сервис занят или лежит, и когда повтор создаёт дубль
Иван Недомолков · Опубликовано:
Таймаут в обмене означает одно из двух: принимающий сервис недоступен или он занят. Снаружи эти случаи не различить, запрос просто висит, а лечатся они по-разному. От этого зависит и главный вопрос: можно ли включить повторные попытки и не получить дубли.
Числа ниже из одного разбора. Ночная синхронизация документов с внешним сервисом четыре ночи подряд падала по таймауту записи, а на четвёртую сервис перестал отвечать совсем.
Занят или недоступен: три замера
| Замер | Сервис недоступен | Сервис занят |
|---|---|---|
| ping до хоста | может не отвечать | отвечает |
| соединение с портом | не устанавливается | устанавливается быстро |
| запрос по HTTP | не уходит | висит без ответа |
У нас хост пинговался, соединение с портом устанавливалось за три миллисекунды, а запрос приложения висел. Раз порт принимает соединения, процесс жив: система ставит соединение в очередь, а приложение до неё не добирается. Если соединение не устанавливается вовсе, смотрят сеть, правила фильтрации и то, запущен ли процесс.
С Windows порт проверяется одной командой, в выводе нужна строка TcpTestSucceeded:
Test-NetConnection -ComputerName service.example.local -Port 443
Проверка живости должна писать
Первые три ночи любая проверка показывала норму. Чтение отвечало за 40-130 миллисекунд с кодом 200, а запись занимала 24 секунды, потом больше тридцати, при жёстком пороге клиента в 30 секунд без повторов. Часть операций укладывалась, часть нет, и какая именно, решала нагрузка.
Проверка, которая только читает, про запись ничего не знает. Если обмен пишет, проверка тоже должна писать, хотя бы в служебный объект, и мерить время этой записи. Похожую ловушку мы встречали на 1С:Шине: брокер отвечал на heartbeat кодом 200, когда обмены уже стояли, разбор эксплуатации Шины здесь.
Таймаут в 1С по умолчанию не задан
У HTTPСоединение параметр Таймаут по умолчанию равен нулю, и по синтакс-помощнику ноль означает “не устанавливать таймаут”. Запрос к занятому сервису в таком случае ждёт ответа столько, сколько сервис молчит. Таймаут задают явно, шестым параметром конструктора:
Соединение = Новый HTTPСоединение(Сервер, , , , , 90, Новый ЗащищенноеСоединениеOpenSSL);
Порог выбирают по замеру записи. В разборе его подняли до 90 секунд, а позже увидели запись длиной 77 секунд. Запас в 17 процентов даёт отсрочку до следующего роста нагрузки, причину медленной записи он не лечит.
Вызов, который ничего не меняет, но дорого стоит
Нагрузку создавал наш код. После обновления каждого документа синхронизация безусловно вызывала перемещение документа в нужный раздел, даже если он там уже лежал: около 1 400 вызовов за прогон на коллекции из 1 417 документов. Рядом стоял комментарий, что операция безопасна и ничего не меняет.
Результат и правда не менялся. Зато на каждый вызов сервис синхронно запускал три своих обработчика и пересчитывал структуру коллекции весом 139 КБ в том же потоке, которым отвечал на запросы: веб-интерфейс, фоновый обработчик и совместное редактирование крутились у него в одном процессе и одном цикле событий. Пока шёл пересчёт, разбирать входящие соединения было некому.
Лечили с двух сторон:
- в нашем коде перед вызовом сравниваем, где документ лежит сейчас и где должен, и перемещаем только при расхождении;
- сервис перевели на пять процессов, и фоновая работа перестала блокировать ответы.
Контрольный прогон: пять баз из пяти, код возврата 0, перемещений 0 вместо примерно 1 400, 344 секунды, следующий прогон 215 секунд. Сервис отвечал кодом 200 за 47 миллисекунд при загрузке процессора 77-89 процентов: отказ давала работа в потоке ответов, её объём был вторичен.
В обменах 1С правило то же: идемпотентная операция может стоить как настоящая, поэтому перед вызовом на той стороне проверьте, нужен ли он. Сравнение текущего состояния с целевым обходится в одно условие.
Какие операции можно повторять
После правок порог записи подняли до 90 секунд и поставили три попытки вместо одной. Тут всплыла вторая опасность: создание документа на таймауте неидемпотентно. Сервер успел применить запись, ответ до клиента не дошёл, клиент повторяет, и в приёмнике два одинаковых документа. При записи на десятки секунд таймаут как раз и наступал, когда сервер работу уже начал.
| Операция | Повтор вслепую | Что сделать перед повтором |
|---|---|---|
| чтение | можно | ничего |
| запись значения, которое не зависит от прошлого | можно | ничего, результат тот же |
| создание | нельзя | проверить, не появился ли объект |
| архивация, удаление | осторожно | перечитать текущее состояние объекта |
Создание в разборе закрыли проверкой перед повтором: ищем документ с таким заголовком, и если он уже есть, повтор превращается в чтение. На встроенном языке схема выглядит так:
Функция СоздатьСПроверкой(Соединение, Ключ, Тело) Экспорт
Для НомерПопытки = 1 По 3 Цикл
Если НомерПопытки > 1 Тогда
Найденный = НайтиНаСтороне(Соединение, Ключ);
Если Найденный <> Неопределено Тогда
Возврат Найденный; // прошлая запись дошла, повтор стал чтением
КонецЕсли;
КонецЕсли;
Попытка
Возврат ОтправитьСоздание(Соединение, Тело);
Исключение
Если НомерПопытки = 3 Тогда
ВызватьИсключение;
КонецЕсли;
ЗаписьЖурналаРегистрации("Обмен.ПовторСоздания", УровеньЖурналаРегистрации.Предупреждение,,,
ПодробноеПредставлениеОшибки(ИнформацияОбОшибке()));
КонецПопытки;
КонецЦикла;
КонецФункции
НайтиНаСтороне и ОтправитьСоздание ваши. Поиск идёт по естественному ключу: заголовку, номеру, внешнему идентификатору. Отправка бросает исключение на таймауте и обрыве соединения, а ответ сервера с кодом ошибки разбирает сама. Неудачная попытка уходит в журнал регистрации: повтор, о котором никто не знает, прячет проблему так же, как пустой перехват. Если естественного ключа у объекта нет, проверить нечем, и повторять создание тогда нельзя совсем.
Код ответа описывает попытку
В той же связке систем пакетная архивация записала в журнал FAILED на все 35 документов, а заархивированы оказались все 35, с шагом около полусекунды на вызов. Обёртка над вызовами на любой ответ, кроме 200, возвращала пустой словарь без исключения, и вызывающий код спокойно шёл дальше. Ответ 403 на архивацию означал “уже заархивировано”, хотя права у сервисного пользователя были администраторские.
Когда операция важна, после неё перечитывают состояние объекта. С него же начинают разбор, до прав доходят потом. На встроенном языке тот же глушитель выглядит как пустой блок Исключение вокруг вызова: во внешних обработках и отчётах такие места находит анализ кода, с номером строки у каждой находки. Карточка обработки на Инфостарте.
Ещё два урока той же аварии
- Пять баз обрабатывались в одном блоке перехвата ошибок, и падение одной останавливало остальные четыре. Перехват нужен свой на каждую базу.
- Сборка с исправлением прошла, а на проде ничего не поменялось: фильтр путей в выкатке не включал каталог со скриптами. У ночного задания должно быть своё окно выкатки, и доезд правки до прода проверяют отдельно от зелёной сборки.
Чего разбор не закрыл
Почему запись идёт дольше минуты, не выяснили: её обошли порогом и повторами. Фоновая загрузка процессора около 83 процентов тоже осталась без объяснения, просто перестала мешать. Пары “до и после” нет: время прогона до аварии никто не мерил, поэтому снимите его у себя сейчас, пока всё работает.