Поиск утечек памяти в 1С: пошаговая методика анализа CALL+LEAKS в технологическом журнале

17.04.26

База данных - HighLoad оптимизация

Пошаговая методика поиска утечек памяти в 1С через технологический журнал: как связать события CALL и LEAKS по clientID, агрегировать тысячи строк стеков вызовов в компактное дерево сценариев, классифицировать проблему без открытия конфигуратора и упаковать результат в готовую задачу разработчику — с bash-скриптами для каждого шага и разбором на реальном примере

Предисловие автора

Методика сложилась при разборе утечек на рабочем сервере. Как оказалось, поиск утечек памяти — нетривиальная операция. Гигабайты логов, события LEAKS c тысячами строк стека вызовов.

Уточню, что в скриптах нет академической строгости. Скрипты написаны под конкретную задачу — получить результат здесь и сейчас. Где-то можно было бы добавить проверок, где-то обернуть переменные в кавычки по всем канонам. Кто-то заметит, что код можно упаковать в два-три раза компактнее. Можно. Но зачем? Развёрнутые скрипты проще понять, адаптировать и, если что, починить. Все имена модулей, серверов и пользователей в примерах изменены. Совпадения случайны. Платформа 8.3.27, окружение Git Bash с GNU утилитами.

 

Шаг 0. Предварительная диагностика: есть ли утечка?

Первый этап анализа — понять, действительно ли мы имеем дело с утечкой, а не со штатным поведением платформы.

 

Как устроены утечки памяти в 1С

Платформа 1С использует автоматическое управление памятью со сборщиком мусора. В большинстве случаев объекты, созданные в серверном коде, освобождаются автоматически после завершения вызова. Однако существуют ситуации, когда объекты не могут быть освобождены:

Циклические ссылки — два или более объекта ссылаются друг на друга. Сборщик мусора 1С исторически не умел разрывать циклические ссылки. В современных версиях платформы механизм улучшен, но полностью полагаться на него не стоит — циклические ссылки остаются частой причиной утечек.

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

Удержание ссылок на тяжёлые объекты — двоичные данные, COM-объекты, HTTP-соединения, которые не обнуляются явно после использования.

 

Как платформа фиксирует утечки в технологическом журнале

Платформа 1С предоставляет два связанных события в технологическом журнале (ТЖ):

Событие CALL — записывается при завершении каждого серверного вызова (обращение клиента к серверу, выполнение фонового задания и т.д.). Содержит итоговые показатели: Memory (потребление на момент завершения), MemoryPeak (максимум за время вызова), Module и Method (точка входа в коде), t:clientID (идентификатор соединения).

Событие LEAKS — записывается после CALL, если платформа обнаружила объекты, которые не были освобождены после завершения вызова. Содержит t:clientID (тот же, что в CALL — это ключ связи) и Descr — подробное описание каждого неосвобождённого объекта: его тип (KeyAndValue, Structure, Array, BinaryData и др.) и полный стек вызовов, показывающий, в какой строке какого модуля объект был создан.

Связка CALL → LEAKS по t:clientID позволяет ответить на три вопроса: какой вызов потребляет много памяти, что именно не освобождается и где в коде это происходит.

Для сбора LEAKS необходимо явно включить параметр <leaks collect="1"/> в logcfg.xml. Без него платформа не выполняет анализ неосвобождённых объектов и событие LEAKS не записывается.

 

Утечка vs. норма

Не каждое высокое потребление памяти — утечка. Важно различать три ситуации:

 

Ситуация Поведение памяти Утечка?

Тяжёлый отчёт / обработка

Выросла → вызов завершился → освободилась

Нет

Кэш платформы (метаданные, сеансовые данные, ПовтИсп - повторное использование возвращаемых значений)

Выросла до фиксированного уровня → стабилизировалась

Нет

Регламентное задание / фоновая обработка

Растёт линейно с каждым вызовом, не возвращается

Да

Избыточное потребление в цикле Стабильно высокая на каждый вызов, но не растёт между вызовами Нет, но требует оптимизации

 

Методика работает для всех четырёх случаев. Даже если анализ покажет, что монотонного роста нет — вы получите ответ на вопрос «что именно потребляет память и где в коде это происходит». Это позволяет принять обоснованное решение: чинить срочно, оптимизировать планово или оставить как есть.

 

Признаки, подтверждающие утечку

Если вы наблюдаете совокупность следующих признаков — это с высокой вероятностью утечка:

Монотонный рост без возврата — на графике мониторинга память рабочего процесса (rphost) только растёт и никогда не снижается до прежнего уровня. Это главный и самый надёжный признак.

Один rphost потребляет значительно больше остальных — если в кластере несколько рабочих процессов и один из них выделяется по памяти, значит утечка привязана к конкретному сеансу или фоновому заданию.

Проблема воспроизводится после перезапуска — если перезапустить rphost, память возвращается к норме, но через некоторое время снова начинает расти по тому же сценарию.

Рост происходит в предсказуемое время — например, ночью, когда работают только регламентные задания. Это сужает круг подозреваемых.

 

Что должно быть готово перед Шагом 1

Данная методика предполагает, что:

  1. Технологический журнал настроен и собирает данные.В xml включены события CALL, LEAKS и параметр <leaks collect="1"/>. Подробная настройка описана в Приложении А.
  2. В логах присутствуют нужные события.Убедитесь, что в каталогах rphost_*/ есть файлы .log, в них встречаются события ,CALL, с полем MemoryPeak= и события ,LEAKS,. Если LEAKS отсутствуют — проверьте xml.
  3. Вы находитесь в каталоге с логами ТЖ(или знаете путь к ним). Все скрипты методики ожидают структуру rphost_*/*.log в текущем каталоге.

 

Шаг 1. Найти самые большие вызовы (CALL), у которых есть пара LEAKS

Получить список «кандидатов» — вызовов с большим MemoryPeak, для которых в логах реально встречается LEAKS с тем же t:clientID. Это отсекает «просто тяжёлые» вызовы от тех, где платформа зафиксировала утечку.

Почему именно так

  • Событие CALL фиксирует завершение серверного вызова и содержит итоговые Memory/MemoryPeak — это «чек» по расходу памяти.
  • Событие LEAKS пишется после CALL для того же t:clientID и содержит Descr — описание неосвобождённых объектов.
  • Связка CALL → LEAKS по t:clientID — основной способ сказать: «этот вызов и тяжёлый, и течёт».

 

Шаг 1.1 — Общая картина по потребляемой памяти 

Когда на сервере несколько баз или десятки фоновых заданий, начинать с поиска конкретных CID неудобно — результат будет слишком объёмным. Сначала группируем по Module.Method, чтобы понять: какие методы текут, сколько баз затронуто, каков масштаб.

# [STEP1_1_GROUP_BY_MODULE_METHOD]
PEAKMB=500
grep -hE ",CALL,|,LEAKS," rphost_*/*.log 2>/dev/null | \
awk -v PEAKMB="$PEAKMB" '
function cid(s,    m) { return (match(s,/t:clientID=([0-9]+)/,m) ? m[1] : "") }
function pkMB(s,   m) { return (match(s,/MemoryPeak=([0-9]+)/,m) ? int(m[1]/1048576) : -1) }
function getf(s,f, m) { return (match(s,f"=([^,]+)",m) ? m[1] : "N/A") }
{
  c = cid($0); if (c == "") next
  if ($0 ~ /,CALL,/) {
    if (pkMB($0) >= PEAKMB) lastCall[c] = $0; else lastCall[c] = ""
    next
  }
  if ($0 ~ /,LEAKS,/ && lastCall[c] != "") {
    if (!seen[c]) {
      seen[c] = 1
      s = lastCall[c]
      mod  = getf(s, "Module")
      meth = getf(s, "Method")
      db   = getf(s, "p:processName")
      match(s, /Memory=([0-9]+)/,    a); mem  = int(a[1]/1048576)
      match(s, /MemoryPeak=([0-9]+)/, a); peak = int(a[1]/1048576)
      match(s, /CpuTime=([0-9]+)/,   a); cpu  = int(a[1]/1000)
      key = mod "|" meth
      cnt[key]++
      sumMem[key]  += mem
      sumPeak[key] += peak
      sumCpu[key]  += cpu
      if (peak > maxPeak[key]) maxPeak[key] = peak
      dbkey = key "|" db
      if (!seenDB[dbkey]) {
        seenDB[dbkey] = 1
        dbCnt[key]++
        if (dbCnt[key] <= 3) dbs[key] = dbs[key] (dbs[key] ? ", " : "") db
      }
    }
  }
}
END {
  # заголовок в stderr — он не попадёт в sort
  printf "%-50s %5s %10s %10s %10s %10s  %s\n", \
    "Module.Method", "Count", "AvgMem", "AvgPeak", "MaxPeak", "AvgCPU_s", "Databases" > "/dev/stderr"
  printf "%-50s %5s %10s %10s %10s %10s  %s\n", \
    "--------------------------------------------------","-----","----------","----------","----------","----------", \
    "-------------------" > "/dev/stderr"
  # данные в stdout — пойдут в sort
  for (k in cnt) {
    split(k, parts, "|")
    dbInfo = dbs[k]
    if (dbCnt[k] > 3) dbInfo = dbInfo ", ... (+" (dbCnt[k]-3) " ещё)"
    printf "%-50s %5d %8d МБ %8d МБ %8d МБ %8d с  %s\n", \
      parts[1] "." parts[2], \
      cnt[k], \
      int(sumMem[k]/cnt[k]), \
      int(sumPeak[k]/cnt[k]), \
      maxPeak[k], \
      int(sumCpu[k]/cnt[k]), \
      dbInfo
  }
}' | sort -k2 -rn | head -20

Пример вывода результата

Module.Method                                            Count     AvgMem    AvgPeak    MaxPeak   AvgCPU_s  Databases
-------------------------------------------------------- ----- ---------- ---------- ---------- ----------  -------------------
ИнтеграцияЭДО.ОбработкаОчередиДокументовЭДО                 6     1885 МБ     1950 МБ     9124 МБ   114046 с  buh_org0, buh_org1
ЭДОФоновыеЗадания.ВыполнитьРегламентныеДействияЭДО         58      473 МБ      582 МБ      631 МБ    19227 с  buh_org1, buh_org2, buh_org3, ... (+10 ещё)
ЛицензированиеСервер.РегламентноеЗаданиеМенеджерСеансов    41      840 МБ      874 МБ      948 МБ    15629 с  buh_org4, buh_org0

Как читать результат

Поле Что показывает На что обращать внимание

Count

Сколько раз метод попал в CALL+LEAKS

Чем больше — тем системнее проблема

AvgMem

Среднее потребление на момент завершения

Сколько «оседает» после вызова

AvgPeak

Средний пик за вызов

Типичная нагрузка на память

MaxPeak

Максимальный пик среди всех вызовов

Худший случай

AvgCPU_s

Среднее процессорное время (секунды)

Косвенный признак объёма работы

Databases

Список затронутых баз

Проблема в одной базе или во всех?

 

Если один и тот же Module.Method встречается в 13 базах с Count=58 — это системная проблема, чинить в первую очередь. Если метод с MaxPeak=9124 МБ встретился 6 раз, но в 2 базах — это тяжёлая локальная проблема, приоритет по критичности ещё выше. Если метод встретился 1 раз с Peak=787 МБ — возможно, разовый инцидент.

Примечание: Каждый CID учитывается только один раз (по первой паре CALL+LEAKS). Если одно долгоживущее фоновое задание генерирует несколько пар CALL+LEAKS за длительный период, в Count попадёт только первая. Для первичного обзора это корректно — на следующих шагах мы увидим полную картину для конкретного CID.

 

Шаг 1.2 — Проверка динамики Memory для выбранного метода

После выбора метода из таблицы Шага 1.1 необходимо проверить, действительно ли память не освобождается между вызовами. Это самая быстрая и дешёвая проверка, которая отсекает ложноположительные срабатывания до начала тяжёлого анализа LEAKS.

Почему это нужно

Событие LEAKS фиксируется платформой при наличии неосвобождённых объектов после завершения вызова. Но «неосвобождённые объекты» — это не всегда утечка. Платформа может фиксировать:

  • Кэш менеджеров метаданных (CatalogManager, EnumManager) — создаётся один раз, живёт до конца вызова
  • Объекты ПовтИсп — штатный механизм повторного использования
  • Сеансовые данные БСП — инициализация при старте фонового задания

Все эти объекты попадают в LEAKS, но не приводят к росту памяти между вызовами. Единственный надёжный способ отличить утечку от штатного поведения — посмотреть, возвращается ли Memory к исходному уровню после завершения вызова.

# [STEP1_2_MEMORY_DYNAMICS]
MODULE_FILTER="ОбработкаОчередиДокументовЭДО"

grep "$MODULE_FILTER" rphost_*/*.log | grep ",CALL," | \
  awk '{
    match($0,/Memory=([0-9]+)/,m); mem=int(m[1]/1048576)
    match($0,/MemoryPeak=([0-9]+)/,p); peak=int(p[1]/1048576)
    printf "%6d МБ / %6d МБ  %s\n", mem, peak, $0
  }' | head -30

Как читать результат

Левая колонка — Memory (сколько памяти «осело» после завершения вызова). Правая — MemoryPeak (максимум во время работы). Важна именно левая колонка — её динамика от строки к строке.

Пример: утечки нет

0 МБ /      4 МБ  ...ОбработкаОчередиДокументовЭДО...
0 МБ /      4 МБ  ...ОбработкаОчередиДокументовЭДО...
0 МБ /      4 МБ  ...ОбработкаОчередиДокументовЭДО...
0 МБ /      4 МБ  ...ОбработкаОчередиДокументовЭДО...
0 МБ /     30 МБ  ...ОбработкаОчередиДокументовЭДО...
0 МБ /     30 МБ  ...ОбработкаОчередиДокументовЭДО...

Memory возвращается к 0 после каждого вызова. MemoryPeak=682 МБ встречается у отдельных вызовов, но это пиковое потребление во время обработки большого объёма данных. После завершения вызова память освобождается. Это не утечка. Переходить к следующему методу из таблицы Шага 1.1.

Пример: утечка есть

200 МБ /    250 МБ  ...ОбработкаОчередиДокументовЭДО...
350 МБ /    400 МБ  ...ОбработкаОчередиДокументовЭДО...
474 МБ /    579 МБ  ...ОбработкаОчередиДокументовЭДО...
510 МБ /    614 МБ  ...ОбработкаОчередиДокументовЭДО...

Memory монотонно растёт от вызова к вызову и не возвращается к исходному уровню. Каждый следующий вызов начинает с того уровня, на котором закончился предыдущий. Это утечка. Продолжать анализ — переходить к Шагу 1.3.

Пример: стабильно высокая (кэш)

1457 МБ /   1480 МБ  ...ОбработкаОчередиДокументовЭДО...
1453 МБ /   1476 МБ  ...ОбработкаОчередиДокументовЭДО...
1453 МБ /   1476 МБ  ...ОбработкаОчередиДокументовЭДО...
1455 МБ /   1477 МБ  ...ОбработкаОчередиДокументовЭДО...

Memory стабильна на высоком уровне, но не растёт. Это фиксированный кэш (ПовтИсп, сеансовые данные). Не утечка, но может потребовать оптимизации, если объём кэша чрезмерный.

Сводная таблица решений

Паттерн Memory Интерпретация Действие
0 → 0 → 28 → 0 → 0 Возвращается к норме Не утечка. Следующий метод
200 → 350 → 474 → 510 Монотонный рост Утечка. Шаг 1.3
500 → 500 → 500 → 500 Стабильно высокая Кэш. Оценить необходимость оптимизации
0 → 0 → 0 → 500 → 500 Однократный скачок, затем стабильна Кэш, загруженный при первом вызове. Не утечка
4621 → 8982 → 1457 → 1453 Скачки, затем стабилизация Тяжёлая обработка + кэш. Шаг 1.3 для анализа состава

 

Если результат неоднозначный

Увеличьте выборку до 50–100 строк (замените head -30 на head -100) и посмотрите на более длинном интервале. Если тренд неочевиден — добавьте фильтр по конкретной базе:

grep "$MODULE_FILTER" rphost_*/*.log | grep ",CALL," | \
  grep "p:processName=buh_org0" | \
  awk '{
    match($0,/Memory=([0-9]+)/,m); mem=int(m[1]/1048576)
    match($0,/MemoryPeak=([0-9]+)/,p); peak=int(p[1]/1048576)
    printf "%6d МБ / %6d МБ\n", mem, peak
  }' | head -50

Это покажет динамику для одной базы, исключив «шум» от разных баз с разным объёмом данных.

Несколько баз — несколько паттернов

Один и тот же метод может вести себя по-разному в разных базах. Например, в одной базе Memory стабильно высокая (кэш), в другой — единичный всплеск до нескольких гигабайт, в третьей — память возвращается к нулю. Если картина неоднородная — фильтруйте по p:processName и анализируйте каждую базу отдельно. Для дальнейшего анализа выбирайте базу с самым тяжёлым или самым повторяемым паттерном.

 

Шаг 1.3 — Получить CID для выбранного метода

После выбора метода из таблицы Шага 1.1 получаем конкретные строки CALL с CID. Переменная MODULE_FILTER задаёт фильтр по имени метода. Если фильтр не нужен — закомментируйте строку с grep.

# [STEP1_3_CALLS_WITH_LEAKS]
PEAKMB=500
MODULE_FILTER="ОбработкаОчередиДокументовЭДО"
grep -HE ",CALL,|,LEAKS," rphost_*/*.log 2>/dev/null | \
grep -E ",LEAKS,|${MODULE_FILTER}" | \
awk -v PEAKMB="$PEAKMB" '
function cid(s,m){ return (match(s,/t:clientID=([0-9]+)/,m)? m[1]:"") }
function pkMB(s,m){ return (match(s,/MemoryPeak=([0-9]+)/,m)? int(m[1]/1048576) : -1) }
{
  # отделяем имя файла (до первого ":")
  match($0, /^([^:]+\.log):(.*)$/, parts)
  fname = parts[1]
  line  = parts[2]
  c=cid(line); if(c=="") next;
  if(line ~ /,CALL,/){
    if(pkMB(line) >= PEAKMB) { lastCall[c]=line; lastFile[c]=fname } else lastCall[c]="";
    next;
  }
  if(line ~ /,LEAKS,/ && lastCall[c]!=""){
    if(!printed[c]){
      print "[CALL_WITH_LEAKS] FILE=" lastFile[c] "\t" lastCall[c];
      printed[c]=1;
    }
  }
}' | tee results.txt | head -20
echo "[STEP1] Total: $(wc -l < results.txt) lines saved to results.txt"

В терминал выводятся первые 20 строк. Полный результат сохраняется в results.txt для использования в следующих шагах.

Пример результата

[CALL_WITH_LEAKS] FILE=rphost_69708/26041119.log    57:40.021001-778379997,CALL,1,
level=INFO,process=rphost,OSThread=5004,t:clientID=10857,callWait=0,first=1,
Usr=Svc_edo,SessionID=22291,p:processName=buh_org0,Func=Background job,
Module=ИнтеграцияЭДО,Method=ОбработкаОчередиДокументовЭДО,
Memory=9418812928,MemoryPeak=9567572248,InBytes=215530840,
OutBytes=156175074,CpuTime=515343750

Строка grep -E ",LEAKS,|${MODULE_FILTER}" пропускает все события LEAKS (они нужны для связки по clientID) и только те CALL, в которых встречается искомый метод. Остальные CALL отбрасываются до попадания в awk.

Как читать результат работы скрипта

Поле Что это Зачем нужно
t:clientID=10857 Идентификатор клиентского соединения Ключ связи с LEAKS на следующих шагах
Module=ИнтеграцияЭДО Модуль 1С Понимаем, какой код вызвал проблему
Method=ОбработкаОчередиДокументовЭДО Метод Конкретная точка входа
Memory=9418812928 (~8982 МБ) Память на момент завершения Сколько «осело» после вызова
MemoryPeak=9567572248 (~9124 МБ) Пиковое потребление Максимум, достигнутый во время вызова
Usr=Svc_edo Пользователь 1С Для идентификации сценария
Func=Background job Тип вызова Фоновое задание — значит работает без UI

 

Выбор CID для дальнейшего анализа. Если результат содержит несколько строк — выбираем CID с максимальным MemoryPeak:

grep "Module=ИнтеграцияЭДО" results.txt | \
  awk '{match($0,/MemoryPeak=([0-9]+)/,m); print m[1]"\t"$0}' | \
  sort -rn | head -1

Далее с этим CID переходим к Шагу 2.

Если результат пустой

  • Снизить порог: PEAKMB=200 или PEAKMB=100.
  • Проверить наличие логов: ls rphost_*/*.log | head.
  • Проверить, включён ли сбор LEAKS в настройках ТЖ (параметр <leaks> в logcfg.xml).
  • Проверить формат: grep -c ",CALL," rphost_*/*.log | grep -v ":0$" — убедиться, что CALL-события вообще есть.

 

Шаг 2. Найти LEAKS и вырезать содержимое

По t:clientID из Шага 1 найти в логах строку LEAKS  и вырезать фрагмент лога, содержащий полное описание утечки  — список неосвобожденных объектов с их стеками вызовов.

Что мы ищем и зачем

Событие LEAKS содержит в поле Descr полное описание неосвобождённых объектов — их типы и стеки вызовов. Это многострочная запись, которая начинается сразу после заголовка события и может занимать тысячи строк. Именно это описание мы вырезаем для дальнейшего анализа.

# [STEP2_FIND_LEAKS_AND_SLICE]
CID=10857
# Ищем LEAKS по всем файлам — только строку с LEAKS для нужного CID
hit=$(grep -rHn "LEAKS.*t:clientID=${CID}[^0-9]" rphost_*/*.log 2>/dev/null | head -1)
echo "[STEP2] hit=$hit"
file=$(echo "$hit" | cut -d: -f1)
line=$(echo "$hit" | cut -d: -f2)
# Находим конец события LEAKS
end=$(tail -n +$((line+1)) "$file" | grep -n "^[0-9][0-9]:[0-9][0-9]\." | head -1 | cut -d: -f1)
end=$((line + end - 1))
start=$(( line>1 ? line-1 : 1 ))
sed -n "${start},${end}p" "$file" > "ctx_${CID}.log"
echo "[STEP2] written ctx_${CID}.log ($(wc -l < ctx_${CID}.log) lines)"
  1. grep -rn "LEAKS.*t:clientID=${CID}[^0-9]" — ищет строку LEAKS с нужным clientID по всем rphost-логам. Суффикс [^0-9] исключает ложные совпадения (например, CID=46 не совпадёт с CID=460)..
  2. tail -n +$((line+1)) | grep -n "^[0-9][0-9]:[0-9][0-9]\." — от следующей строки после LEAKS ищет начало следующего события ТЖ (строка с временной меткой). Это конец описания утечки.
  3. sed -n "${start},${end}p" — вырезает фрагмент: 1 строку до LEAKS (CALL для этого же CID) и всё описание утечки до конца события.

Что мы увидим в результате выполнения

[STEP2] hit=rphost_69708/26041119.log:14379641:57:40.052000-0,LEAKS,1,
level=DEBUG,process=rphost,OSThread=5004,t:clientID=10857,
t:applicationName=BackgroundJob,t:computerName=app1,
t:connectID=365898,Descr='
KeyAndValue:
[STEP2] written ctx_10857.log (76929 lines)

 Как читать результат

Поле

Что это

Зачем нужно

:14379641:

Номер строки

Можем вернуться к сырому логу при необходимости

t:applicationName=BackgroundJob

Тип приложения

Подтверждает: утечка в фоновом задании

t:connectID=365898

ID соединения

Дополнительный идентификатор для корреляции

Descr='

Начало описания утечки

Дальше идет список объектов с типами и стеками вызовов

 

Что внутри файла ctx_10857.log

  • 1-2 строки до—предшествующее событие (CALL строка для этого же ClientID)
  • Строка LEAKS— заголовок события с t:clientIDt:applicationName и началом Descr='
  • Десятки тысяч строк описания — при тяжёлых вызовах (гигабайты памяти) файл может содержать 50 000–100 000 строк. В нашем случае 76 929 строк для вызова с пиком 9 ГБ:
KeyAndValue:
  ЭДО Обработка.ЭДОЯдро.МодульОбъекта : 16801 : ...
  ЭДО Обработка.МодульЕДО.МодульОбъекта : 8396 : ...
  ...

Если hit пустой

  • Проверить, есть ли LEAKS вообще: grep -rc "LEAKS" rphost_*/*.log | grep -v ":0$"
  • Проверить CID: grep -r "t:clientID=${CID}[^0-9]" rphost_*/*.log | head -3
  • Проверить, что CID правильный: номер должен совпадать с тем, что показал Шаг 1.3

Большие файлы LEAKS. При анализе вызовов с потреблением в несколько гигабайт событие LEAKS может содержать десятки тысяч строк. Команда tail -n +<номер> на файле в миллионы строк может работать медленно. Если поиск конца события занимает больше минуты — ограничьте поиск: tail -n +$((line+1)) "$file" | head -500000 | grep -n "^[0-9][0-9]:[0-9][0-9]\." | head -1.

 

Шаг 3. Агрегировать содержимое LEAKS: "что течёт" и "куда копать"

Из ctx_<CID>.log получить два среза:

  1. ТОП типов объектов— какие типы данных 1С «текут» (KeyAndValue, Array, Structure, ValueTable, BinaryData и т.п.)
  2. ТОП строк кода— какие конкретные строки модулей чаще всего встречаются в стеках утёкших объектов

Это даёт первичное понимание: что утекает и откуда.

3.1 - ТОП типов объектов

# [STEP3_TOP_TYPES]
CID=10857
grep -oE "^[^[:space:]][^:]+:" ctx_${CID}.log | \
sort | uniq -c | sort -rn | head -30
  1. grep -oE "^[^[:space:]][^:]+:" — ищет строки, начинающиеся с непробельного символа и заканчивающиеся двоеточием. В содержимом LEAKS так записаны типы объектов: KeyAndValue:, Array:, Structure:, а также составные имена вроде EnumManager.ВидыСвойств:, InformationRegisterManager.НастройкиОтчетов:.

  2. sort | uniq -c | sort -rn— классический подсчёт уникальных значений с сортировкой по убыванию.

В результате выполнения скрипта мы видим

5538 KeyAndValue:
      1 FixedArray:
Ключ Количество Элемент коллекции Важность
KeyAndValue: 5538 (Структура, Соответствие, ФиксированнаяСтруктура) — пара «ключ-значение» Высокая — массовое создание, признак накопления в цикле
FixedArray: 1 Фиксированный массив Низкая — единичный, скорее контейнер верхнего уровня
Structure: Структура Зависит от количества
ValueTable: Таблица значений Высокая. Если много — тяжёлые данные
BinaryData: Двоичные данные (файлы, картинки) Высокая. Очень тяжёлые объекты
COMObject: Внешний COM-объект Высокая. Часто не освобождается автоматически

Вывод по нашему случаю: 5538 объектов KeyAndValue при 1 объекте FixedArray — это массовое создание пар «ключ-значение» в цикле обработки очереди документов. Масштаб (тысячи объектов) соответствует количеству документов в очереди. FixedArray — единичный, скорее контейнер верхнего уровня.

 

3.2 - ТОП строк кода

# [STEP3_TOP_CODELINES]
CID=10857
grep -oE "[^[:space:]]+ : [0-9]+ :" ctx_${CID}.log | \
sort | uniq -c | sort -rn | head -50
  1. grep -oE "[^[:space:]]+ : [0-9]+ :"— ищет паттерн Модуль : НомерСтроки :, который платформа 1С использует в стеках LEAKS для указания точки в коде.
  2. Подсчёт и сортировка — аналогично 3.1.

При выполнении мы увидим подобный результат

5491 ОбщийМодуль.ИнтеграцияЭДО.Модуль : 364 :
   5251 ОбщийМодуль.ИнтеграцияЭДО.Модуль : 695 :
   4691 РегистрСведений.СписокДокументовОтправкаПакетовЭДО.МодульМенеджера : 14 :
   4638 ОбщийМодуль.ИнтеграцияЭДО.Модуль : 1354 :
   4634 Обработка.ЭДОЯдро.МодульОбъекта : 29769 :
   4634 Обработка.ЭДОВызовы.МодульОбъекта : 6246 :
   4634 Обработка.ЭДОВызовы.МодульОбъекта : 5894 :
   3950 Обработка.ЭДОЯдро.МодульОбъекта : 29632 :
   3950 Обработка.ЭДОЯдро.МодульОбъекта : 16418 :
   3950 Обработка.ЭДОХранениеДанных.МодульОбъекта : 16122 :
   3950 Обработка.ЭДОХранениеДанных.МодульОбъекта : 14115 :
   3950 Обработка.ЭДОХранениеДанных.МодульОбъекта : 13747 :
    729 ОбщийМодуль.ИнтеграцияЭДО.Модуль : 23 :
    514 Обработка.ЭДОСтандартУФ.МодульОбъекта : 165 :
    496 Обработка.ЭДОЯдро.МодульОбъекта : 29673 :
    ...

Результат — это «тепловая карта» кода: чем больше число слева, тем чаще эта строка встречается в стеках утёкших объектов.

Структура данных (три уровня):

Уровень Счётчик Строки Интерпретация
Ядро цикла 5491–4634 :364, :695, :14, :1354, :29769, :6246, :5894 Точка входа и общий путь — почти все объекты проходят здесь
Тело операции 3950 :29632, :16418, :16122, :14115, :13747 ЭДОХранениеДанных — здесь создаются основные данные (71% объектов)
Ветвления 100–729 :23, :165, :29673 и т.д. Разные ветки: инициализация, виды пакетов, метрика

Правило чтения:

  • Строки с близким счётчиком (5491, 5251, 4691, 4638, 4634) — это один и тот же стек вызовов на разных уровнях вложенности. Небольшие расхождения (5491 vs 4634) означают, что часть объектов создаётся до ветвления.
  • Резкое падение счётчика (4634 → 3950 → 729 → 496) — точки ветвления: код расходится на разные сценарии.
  • Доминирующая группа 3950 (71%) — основная зона накопления данных в ЭДОХранениеДанных.

Визуализация цепочки по нашим данным:

5491 :364                                     -- точка входа (ПроверитьОбновитьКэшПоДокументу)
5251 :695                                     -- ОбновитьСписокДокументов
  |
4691 ---- :14 АвторизоватьсяПодЛогином        |
4638 ---- :1354 ЭДО_Авторизоваться            | основной ствол
4634 ---- :5894 > :6246 > :29769              |
  |
3950 ---- :29632 > :16418 > :13747            | ЭДОХранениеДанных (71%)
  |
 729 ---- :23 Инициализация                   | ветка инициализации
 496 ---- :29673 Metadata.Вставить            | ветка метаданных

Что это даёт: 

  • Верхние строки (5491–4634) — точка входа и основной ствол, менять здесь обычно не нужно.
  • Группа 3950 — зона, где создаются основные данные (ЭДОХранениеДанных). Здесь искать причину.
  • Строки 100–729 — побочные ветки (инициализация, метаданные), чинить во вторую очередь.

Если типов объектов много и разных

Когда в результате работы скрипта из 3.1 видим разнородную картину:

1500 KeyAndValue:
     800 Structure:
     200 Array:
     150 BinaryData:
      50 ValueTable:

Это означает несколько разных утечек в одном вызове. Нужно повторить Шаг 6 отдельно для каждого типа (заменив KeyAndValue на Structure, BinaryData и т.д.).

 

Шаг 4. Классифицировать проблему

По результатам Шагов 1–3 определить тип проблемы и приоритет исправления, не заглядывая в код 1С. 

Матрица классификации

Признак объекта

Накопление в цикле

Кэш/ПовтИсп

Тяжелые объекты

Внешние ресурсы

Тип объекта

KeyAndValue, Structure, Array

KeyAndValue, Structure

BinaryData, ValueTable, HTTPResponse

COMObject, XMLWriter

Счётчик в 3.2

Десятки–сотни одинаковых

1–5

1–10, но Memory огромный

1–10

Повторяемость строк

Одни и те же строки ×N

Уникальные строки

Мало строк, но большой Memory

Мало строк

Наличие ПовтИсп

Нет или мало

Доминирует

Нет

Нет

Приоритет

Срочно — линейный рост памяти

Низкий — фиксированный объём

Высокий — скачкообразный рост

Срочно — возможна утечка за пределами 1С

 

Применение к нашему случаю

Признак Значение Интерпретация
Тип объекта KeyAndValue: (5538) Пары ключ-значение из структур
Счётчик 3950 одинаковых стеков Массовый цикл по документам
ПовтИсп Нет Не кэш платформы
Memory/MemoryPeak 1457 / 1480 МБ (стабильно) Тяжёлый, но не растёт
Паттерн Memory Стабильная между вызовами Не классическая утечка

 Классификация: Избыточное создание объектов в цикле. Формально не утечка (память не растёт между вызовами), но каждый вызов фонового задания потребляет ~1.5 ГБ из-за повторной авторизации и загрузки справочника на каждый документ в очереди. Приоритет — высокий (оптимизация).

Что подготовить для задачи по исправлению (3 артефакта)

1

CALL-строка

Шаг 1

Текст — одна строка с Module, Method, Memory, MemoryPeak

2

Сводка анализа

Шаги 3–4

Текст — TOP_TYPES (10 строк) + TOP_CODELINES (20 строк) + классификация

3

Срез лога с описанием утечки

Шаг 2

Файл ctx_<CID>.log — для просмотра содержимого LEAKS

Скрипт для выделения top-5 точек входа

# [STEP4_TOP5_CODELINES]
CID=10857
grep -oE "[^[:space:]]+ : [0-9]+ :" ctx_${CID}.log | \
sort | uniq -c | sort -rn | head -5

Это тот же скрипт из Шага 3.2, но берём только top-5 для компактности

Пример результата работы

5491 ОбщийМодуль.ИнтеграцияЭДО.Модуль : 364 :
5251 ОбщийМодуль.ИнтеграцияЭДО.Модуль : 695 :
4691 РегистрСведений.СписокДокументовОтправкаПакетовЭДО.МодульМенеджера : 14 :
4638 ОбщийМодуль.ИнтеграцияЭДО.Модуль : 1354 :
4634 Обработка.ЭДОЯдро.МодульОбъекта : 29769 :

Как читать: это не «5 разных проблем», а один стек

Все пять строк имеют близкие счётчики (5491–4634) — значит они встречаются вместе в стеке почти каждого утёкшего объекта. Небольшие расхождения означают, что часть объектов создаётся до ветвления на разные сценарии.

Это цепочка вызовов:

[1] ИнтеграцияЭДО : 364        — точка входа (ПроверитьОбновитьКэшПоДокументу)
[2] ИнтеграцияЭДО : 695        — ОбновитьСписокДокументов
[3] СписокДокументовЭДО : 14   — авторизация перед обновлением
[4] ИнтеграцияЭДО : 1354       — ЭДО_АвторизоватьсяПодЛогином
[5] ЭДОЯдро : 29769            — проверка ТипыДокументовAPI (после авторизации)

Для разработчика важны строки [3]–[5] — на каждой итерации цикла по документам вызывается авторизация, после которой загружается справочник типов документов. Оба действия можно выполнить один раз перед циклом.

 

Шаг 5. Вытащить «окрестность стека» по топ-строкам

Этот шаг опциональный. Выполняется при первом анализе незнакомого кода или когда результат Шага 3.2 неоднозначен. При повторном анализе похожих случаев — переходить сразу к Шагу 6.

Дать разработчику не просто список Модуль : строка, а контекст: какие типы объектов и какой стек вызовов окружают каждую топ-строку. Это позволяет увидеть причинно-следственную связь: «в этом месте кода создаётся вот такой объект».

Почему это нужно

Результат Шага 3 — это «плоский» список. Он не показывает:

  • Какой тип объекта создаётся в конкретной строке
  • Какие вызовы идут до и после
  • Есть ли цикл (повторяющийся паттерн)

Шаг 5 восстанавливает эту связь из содержимого LEAKS.

# [STEP5_SHOW_CONTEXT_AROUND_TOPLINES]
CID=10857
for pat in \
"ОбщийМодуль.ИнтеграцияЭДО.Модуль : 364 :" \
"ОбщийМодуль.ИнтеграцияЭДО.Модуль : 695 :" \
"РегистрСведений.СписокДокументовОтправкаПакетовЭДО.МодульМенеджера : 14 :" \
"ОбщийМодуль.ИнтеграцияЭДО.Модуль : 1354 :" \
"Обработка.ЭДОЯдро.МодульОбъекта : 29769 :" \
; do
  echo "===== $pat ====="
  grep -nF "$pat" "ctx_${CID}.log" | head -3 | cut -d: -f1 | \
  while read -r n; do
    echo "--- hit at line $n ---"
    start=$(( n>20 ? n-20 : 1 ))
    end=$(( n+20 ))
    sed -n "${start},${end}p" "ctx_${CID}.log"
  done
done

Как работает скрипт

  1. Цикл for pat in ...— перебирает top-5 строк кода из Шага 4.
  2. grep -nF "$pat"— ищет каждую строку в ctx_<CID>.log с номером строки (-n) и точным совпадением (-F).
  3. head -3— берём максимум 3 вхождения (больше обычно не нужно — паттерн повторяется).
  4. sed -n "${start},${end}p"— вырезаем окно ±20 строк вокруг каждого вхождения.

Пример одного блока

===== ОбщийМодуль.ИнтеграцияЭДО.Модуль : 1354 : =====
--- hit at line 5 ---
KeyAndValue:
    ЭДО Обработка.ЭДОХранениеДанных.МодульОбъекта : 13747 :
      Результат = ДопСправочники_СписокЭлементов(ИмяСправочника, ПереченьРеквизитов);
    ЭДО Обработка.ЭДОХранениеДанных.МодульОбъекта : 14115 :
    ЭДО Обработка.ЭДОХранениеДанных.МодульОбъекта : 16122 :
    ЭДО Обработка.ЭДОЯдро.МодульОбъекта : 16418 :
      Результат = Модуль_ХранениеДанных.ДопСправочники_СписокЭлементов(...);
    ЭДО Обработка.ЭДОЯдро.МодульОбъекта : 29632 :
      ТипыДокументовAPI = ХранениеДанных_СписокЭлементовДопСправочника(...);
    ЭДО Обработка.ЭДОЯдро.МодульОбъекта : 29769 :
      ТипыДокументовAPI = ПредопределенныеСписки_ТипыДокументовAPI();
    ЭДО Обработка.ЭДОВызовы.МодульОбъекта : 6246 :
      Ядро.ТипыДокументовAPI_ПроверитьНаличие();
    ЭДО Обработка.ЭДОВызовы.МодульОбъекта : 5894 :
      ОбработатьСобытияПослеАвторизации();
    ЭДО ОбщийМодуль.ИнтеграцияЭДО.Модуль : 1354 :
      Токен = ЭДОВызовы.ЭДО_АвторизоватьсяПодЛогином(...);
    ЭДО РегистрСведений.СписокДокументовОтправкаПакетовЭДО.МодульМенеджера : 14 :
      Токен = ИнтеграцияЭДО.АвторизоватьсяПодЛогином(...);
    ЭДО ОбщийМодуль.ИнтеграцияЭДО.Модуль : 695 :
      ОбновитьСписокДокументов(ПараметрыОтправки);
    ЭДО ОбщийМодуль.ИнтеграцияЭДО.Модуль : 364 :
      ПроверитьОбновитьКэшПоДокументу(СтрокаОчереди.Документ1С);
KeyAndValue:
    ЭДО Обработка.ЭДОХранениеДанных.МодульОбъекта : 13747 :
    ...

Как читать результат Шага 5, структура одного блока:

KeyAndValue:                          — ТИП неосвобождённого объекта
    ...ЭДОХранениеДанных : 13747 :    — где создан объект (глубина стека)
      Результат = ДопСправочники_...  — код строки
    ...ЭДОЯдро : 16418 :
    ...ЭДОЯдро : 29632 :             — загрузка справочника ТипыДокументовAPI
    ...ЭДОЯдро : 29769 :
    ...ЭДОВызовы : 6246 :            — проверка после авторизации
    ...ЭДОВызовы : 5894 :            — ОбработатьСобытияПослеАвторизации
    ...ИнтеграцияЭДО : 1354 :        — авторизация
    ...СписокДокументовЭДО : 14 :    — вызов авторизации из обновления списка
    ...ИнтеграцияЭДО : 695 :         — ОбновитьСписокДокументов
    ...ИнтеграцияЭДО : 364 :         — точка входа
KeyAndValue:                          — СЛЕДУЮЩИЙ объект (тот же паттерн!)

На что обращать внимание:

Тип перед стеком

KeyAndValue:, Array:, Structure:

Понимаем, что именно создаётся в этой точке

Повторяемость блоков

Одинаковые блоки идут подряд

Подтверждение цикла — каждая итерация создаёт объект

Код строки (если виден)

Токен = ...АвторизоватьсяПодЛогином(...)

Конкретная операция, создающая объект

Порядок стека

От «глубокого» вызова к точке входа

Восстанавливаем цепочку: кто кого вызвал

Ключевой признак проблемы в нашем случае:

Блоки KeyAndValue: с идентичным стеком идут один за другим — это значит, что один и тот же код на каждой итерации создаёт KeyAndValue, и ни один из них не освобождается до завершения всего вызова.

Чек-лист по результатам Шага 5

По каждому «снимку» отвечаем на вопросы:

# Вопрос Как определить Наш случай
1 Это создание данных в цикле? Одинаковые блоки подряд = да Да — 3950+ одинаковых блоков
2 Что создаётся? Тип перед стеком KeyAndValue — пара ключ-значение
3 Где создаётся? Верхняя строка стека :13747 в ЭДОХранениеДанных
4 Кто вызывает? Следующие строки стека :1354 → ЭДО_АвторизоватьсяПодЛогином → :5894 → ТипыДокументовAPI
5 Есть ли сброс между итерациями? Искать в коде = Неопределено / .Очистить() Нет — объекты накапливаются
6 Можно ли вынести из цикла? Если результат не зависит от итерации Авторизацию и загрузку справочника можно выполнить один раз перед циклом

 

Шаг 6. Свести LEAKS к «повторяющемуся сценарию» и выделить подозрительный участок цикла

Автоматически сгруппировать утёкшие объекты по сигнатуре стека — уникальной цепочке вызовов. Это заменяет ручной просмотр содержимого LEAKS (как в опциональном Шаге 5) и даёт точный ответ: сколько разных «сценариев утечки» существует и какой из них доминирует.

Почему нельзя остановиться на Шаге 5

Шаг 5 показывает 1–3 примера для каждой топ-строки. Но:

  • Одна строка кода может участвовать в разных цепочках вызовов
  • Разные ветки кода могут проходить через одну и ту же строку
  • Без группировки непонятно, сколько объектов создаёт каждый сценарий

Шаг 6 решает эту проблему: берёт полный стек каждого объекта, приводит к единому формату и считает повторения.

# [STEP6_STACK_SIGNATURES]
CID=10857
DEPTH=8
awk -v DEPTH="$DEPTH" '
# Ловим начало любого утёкшего объекта
/^[^[:space:]].*:$/ {
  capturing = 1
  k = 0
  sig = ""
  next
}
capturing && / : [0-9]+ :/ {
  # нормализуем пробелы
  gsub(/^[[:space:]]+/, "")
  gsub(/[[:space:]]+$/, "")
  gsub(/[[:space:]]+/, " ")
  sig = sig $0 "|"
  k++
  if (k >= DEPTH) {
    counts[sig]++
    capturing = 0
  }
  next
}
# Любая строка, не похожая на стек, прерывает захват
capturing && !( / : [0-9]+ :/ ) {
  # Если успели набрать хотя бы 1 строку — считаем укороченную сигнатуру
  if (k > 0) counts[sig]++
  capturing = 0
}
END {
  for (s in counts) {
    print counts[s] "\t" s
  }
}
' "ctx_${CID}.log" | sort -rn | head -20

Как работает скрипт (пошагово)

  1. Триггер /^[^[:space:]].*:$/ — обнаруживает начало нового утёкшего объекта в описании утечки. Ловит любую строку, начинающуюся с непробельного символа и заканчивающуюся двоеточием — это универсальный паттерн для всех типов объектов (KeyAndValue:, Structure:, Array: и т.д.).
  2. Захват стека— следующие строки, содержащие : число : (формат стека 1С), собираются в строку-сигнатуру через разделитель |.
  3. Ограничение глубины DEPTH=8— берём первые 8 уровней стека. Этого достаточно, чтобы различить сценарии, но не перегрузить группировку.
  4. Прерывание захвата— если встретилась строка без паттерна стека, захват останавливается (стек закончился).
  5. Агрегация counts[sig]++— одинаковые сигнатуры суммируются.
  6. Сортировка— самые частые сигнатуры наверху.

Параметр DEPTH

4–5

Грубая группировка, много разных стеков

Может объединить разные сценарии

8

Стандарт — различает основные ветки

Оптимальный баланс

12–15

Детальная группировка

Может «разбить» один сценарий на подварианты

Как адаптировать для других типов объектов

Если в Шаге 3.1 доминирует не KeyAndValue, а другой тип — заменяем триггер:

# Для Structure:
/^[[:space:]]*Structure:/ {

# Для BinaryData:
/^[[:space:]]*BinaryData:/ {

# Для любого типа (универсально):
/^[^[:space:]][^:]+:$/ {

Пример результата

3950  ...ИнтеграцияЭДО.Модуль : 364 : ПроверитьОбновитьКэшПоДокументу|
      ...ИнтеграцияЭДО.Модуль : 695 : ОбновитьСписокДокументов|
      ...СписокДокументовОтправкаПакетовЭДО : 14 : АвторизоватьсяПодЛогином|
      ...ИнтеграцияЭДО.Модуль : 1354 : ЭДО_АвторизоватьсяПодЛогином|
      ...ЭДОВызовы : 5894 : ОбработатьСобытияПослеАвторизации|
      ...ЭДОВызовы : 6246 : ТипыДокументовAPI_ПроверитьНаличие|
      ...ЭДОЯдро : 29769 : ПредопределенныеСписки_ТипыДокументовAPI|
      ...ЭДОЯдро : 29632 : ХранениеДанных_СписокЭлементовДопСправочника|
      ...ЭДОЯдро : 16418 : ДопСправочники_СписокЭлементов|
      ...ЭДОХранениеДанных : 13747 : ДопСправочники_СписокЭлементов_Диадок|
 496  ...тот же ствол до :29769...|
      ...ЭДОЯдро : 29673 : Metadata.Вставить|
 188  ...тот же ствол до :29769...|
      ...ЭДОЯдро : 29668 : Metadata.Вставить|
 107  ...:364|:695|:25 ОбновитьСписокДокументовКонтекст|
      ...:194 ОчиститьОбработанныеЗаписи|:23 Инициализация|...|
  87  ...:364|:695|:25|:180 СписокДокументов|:31 ПолучитьОбработкуЭДО|:23 Инициализация|...|
  73  ...:364|:681 ПолучитьОбработкуЭДО|:23 Инициализация|...СтандартУФ...|
  65  ...:364|:695|:6 ПолучитьОбработкуЭДО|:23 Инициализация|...|
  48  ...:364|:688 ПолучитьВидыДокументовДляОтбора|:8 МассивВидовПакетов|
      ...:28874 ВидыПакетов|:29154 Новый Структура(КлючиДляОписанияВида)|
  46  ...:364|:695|:25|:178 СписокДокументов_Документы|
      ...:39536 Для Каждого ВидПакета|:28874 ВидыПакетов|:29154 Новый Структура|
  27  ...:364|:695|:14|:1356 ЗаполнитьКонтекстСеанса|...Метрика...|

Как читать результат — дерево сценариев

Все сигнатуры сходятся в одну точку входа (:364 ПроверитьОбновитьКэшПоДокументу) и расходятся на три основные ветки:

Точка входа: :364 ПроверитьОбновитьКэшПоДокументу
  |
  +-- :695 ОбновитьСписокДокументов
  |     |
  |     +-- :14 АвторизоватьсяПодЛогином                    4661 объект (84%)
  |     |     |
  |     |     +-- :1354 ЭДО_АвторизоватьсяПодЛогином
  |     |     |     |
  |     |     |     +-- :5894 > :6246 > :29769 > :29632 > ЭДОХранениеДанных
  |     |     |     |   3950 объектов (71%) -- ТипыДокументовAPI
  |     |     |     |
  |     |     |     +-- :5894 > :6246 > :29769 > :29673 Metadata.Вставить
  |     |     |     |   496 объектов (9%)
  |     |     |     |
  |     |     |     `-- :5894 > :6246 > :29769 > :29668 Metadata.Вставить
  |     |     |         188 объектов (3.4%)
  |     |     |
  |     |     `-- :1356 ЗаполнитьКонтекстСеанса > Метрика
  |     |         27 объектов (0.5%)
  |     |
  |     +-- :25 ОбновитьСписокДокументовКонтекст            240 объектов (4.3%)
  |     |     +-- :194 ОчиститьОбработанныеЗаписи > :23 Инициализация
  |     |     |   107 объектов
  |     |     +-- :180 СписокДокументов > :23 Инициализация
  |     |     |   87 объектов
  |     |     `-- :178 СписокДокументов_Документы > ВидыПакетов
  |     |         46 объектов
  |     |
  |     `-- :6 ПолучитьОбработкуЭДО > :23 Инициализация
  |         65 объектов (1.2%)
  |
  +-- :681 ПолучитьОбработкуЭДО > :23 Инициализация > ЭДОСтандартУФ
  |   73 объекта (1.3%)
  |
  `-- :688 ПолучитьВидыДокументовДляОтбора > ВидыПакетов
      48 объектов (0.9%)

Сводная таблица сценариев

Сценарий Объектов % Точка в коде Суть
Авторизация → ТипыДокументовAPI → ЭДОХранениеДанных 3950 71.3% ДопСправочники_СписокЭлементов Загрузка справочника после авторизации в цикле
Авторизация → Metadata.Вставить 684 12.4% ПредопределенныеСписки_ТипыДокументовAPI Заполнение метаданных при авторизации
Инициализация контекста (разные точки входа) 332 6.0% ИнициализироватьОбщийКонтекст ПолучитьОбработкуЭДО → инициализация в цикле
ВидыПакетов (ПредопределенныеСписки) 94 1.7% ПредопределенныеСписки_ВидыПакетов Новый Структура в цикле по видам
КонтекстСеанса → Метрика 27 0.5% ЗаполнитьКонтекстСеанса Статистика при заполнении контекста
Прочие 451 8.1% Разные Мелкие ветвления
Итого 5538 100%    

 

Главный вывод Шага 6

4634 из 5538 объектов (83.7%) создаются в цепочке АвторизоватьсяПодЛогином → ЭДО_АвторизоватьсяПодЛогином → ОбработатьСобытияПослеАвторизации → ТипыДокументовAPI.

На каждой итерации цикла по документам очереди происходит:

  1. Авторизация в сервисе ЭДО (:14 → :1354)
  2. После авторизации — проверка и загрузка справочника ТипыДокументовAPI (:5894 → :6246 → :29769)
  3. Загрузка справочника из хранилища данных (:29632 → :16418 → :13747)

Результат не освобождается между итерациями. При очереди в тысячи документов это даёт гигабайты неосвобождённых объектов за один вызов фонового задания.

Это не классическая утечка с монотонным ростом между вызовами — память стабилизируется на ~1.5 ГБ и не растёт дальше. Но это избыточное потребление: авторизацию и загрузку справочника можно выполнить один раз перед циклом.

 

Шаг 7. Фиксируем результат

Собрать из результатов Шагов 1–6 готовую задачу, которую разработчик может взять в работу без дополнительных вопросов.

Упаковка артефактов для передачи разработчику

После завершения анализа (Шаги 1–6) у нас накопилось несколько файлов, разбросанных по текущему каталогу. Чтобы передать разработчику готовый комплект — собираем всё в одну папку. Это удобно: можно приложить к задаче в трекере, отправить архивом или положить на общий диск.

Файлы для передачи разработчику

# Файл Содержимое Источник
1 call.txt CALL-строка Шаг 1
2 ctx_10857.log Срез лога с описанием (~76 000 строк) Шаг 2
3 top_types.txt ТОП типов объектов Шаг 3.1
4 top_codelines.txt ТОП строк кода Шаг 3.2
5 stack_signatures.txt Сигнатуры стеков Шаг 6

Скрипт для автоматической упаковки

# [STEP7_PACKAGE]
CID=10857
DIR="case_${CID}"
FILE="rphost_69708/26041119.log"   # файл из hit на Шаге 2
mkdir -p "$DIR"
# CALL-строка — из конкретного файла, найденного на Шаге 2
grep ",CALL,.*t:clientID=${CID}[^0-9]" "$FILE" | \
  tail -1 > "${DIR}/call.txt"
# Содержимое
cp "ctx_${CID}.log" "${DIR}/"
# Типы объектов
grep -oE "^[^[:space:]][^:]+:" "ctx_${CID}.log" | \
  sort | uniq -c | sort -rn > "${DIR}/top_types.txt"
# Строки кода
grep -oE "[^[:space:]]+ : [0-9]+ :" "ctx_${CID}.log" | \
  sort | uniq -c | sort -rn > "${DIR}/top_codelines.txt"
# Сигнатуры стеков
AWK_TMP=$(mktemp /tmp/step7_XXXXXX.awk)
cat > "$AWK_TMP" << 'AWKEOF'
/^[^[:space:]].*:$/ {
  capturing = 1; k = 0; sig = ""; next
}
capturing && / : [0-9]+ :/ {
  gsub(/^[[:space:]]+/, ""); gsub(/[[:space:]]+$/, ""); gsub(/[[:space:]]+/, " ")
  sig = sig $0 "|"; k++
  if (k >= DEPTH) { counts[sig]++; capturing = 0 }
  next
}
capturing { if (k > 0) counts[sig]++; capturing = 0 }
END {
  for (s in counts) print counts[s] "\t" s
}
AWKEOF
awk -v DEPTH=8 -f "$AWK_TMP" "ctx_${CID}.log" | \
  sort -rn > "${DIR}/stack_signatures.txt"
rm -f "$AWK_TMP"
echo "[STEP7] Packaged into ${DIR}/:"
ls -la "${DIR}/"

Результат упаковки данных по расследованию

[STEP7] Packaged into case_10857/:
-rw-r--r-- 1 user user      450 Jun 12 10:00 call.txt
-rw-r--r-- 1 user user  3845000 Jun 12 10:00 ctx_10857.log
-rw-r--r-- 1 user user       52 Jun 12 10:00 top_types.txt
-rw-r--r-- 1 user user     4200 Jun 12 10:00 top_codelines.txt
-rw-r--r-- 1 user user     3800 Jun 12 10:00 stack_signatures.txt

Проверка после исправления

После исправления и переноса доработок на боевой сервер повторите Шаги 1–3 на новых логах:

  • Шаг 1— если метод исчез из результатов или MemoryPeak значительно снизился — исправление сработало
  • Шаг 3— если количество объектов в LEAKS уменьшилось — утечка устранена частично или полностью
  • График мониторинга— если память рабочего процесса rphost перестала расти монотонно — проблема решена
Результат проверки Действие
Метод отсутствует в Шаге 1.1, Memory на вызов снизилась Закрыть задачу
MemoryPeak снизился (например, с 9 ГБ до 500 МБ), LEAKS остались Частичное исправление — повторить Шаги 3–6 для остатка
Memory на вызов не изменилась Исправление не попало или не затронуло основной сценарий
Memory между вызовами перестала расти (если была утечка) Утечка устранена, даже если LEAKS ещё есть

 

Сводная карта методики

Предварительная диагностика

Подтверждение утечки или избыточного потребления

Найти CALL + LEAKS по порогу MemoryPeak

CID, Module, Method, Peak

Найти LEAKS, вырезать содержимое

ctx_<CID>.log

Агрегировать: типы + строки кода

TOP_TYPES, TOP_CODELINES

Классифицировать проблему

Тип: цикл / кэш / тяжёлый

Контекст вокруг топ-строк (опционально)

Снимки стека с типами

Сигнатуры стеков → дерево сценариев

Сценарии утечки

Задача разработчику + упаковка + верификация

case_<CID>/

 

Приложение А. Пример настройки технологического журнала

<?xml version="1.0"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
<log location="E:\1c_logs\log_memory_leaks" history="12">
    <event>
      <eq property="Name" value="CALL"/>
    </event>
    <event>
      <eq property="Name" value="LEAKS"/>
    </event>
    <property name="all"/>
</log>
<leaks collect = "1">
  <point call = "server"/>
</leaks>
</config>

Влияние на производительность

Параметр <leaks collect="1"> включает анализ неосвобождённых объектов после каждого серверного вызова. Это создаёт дополнительную нагрузку:

  • CPU— платформа выполняет обход графа объектов после каждого CALL
  • Диск— события LEAKS содержат полные стеки, логи растут значительно быстрее
  • Память— незначительно, но на нагруженных серверах может быть заметно

Рекомендация: включать на ограниченное время (часы, не дни), в период воспроизведения проблемы. На высоконагруженном продуктиве — согласовать окно сбора. После получения логов — отключить, убрав блок <leaks> из logcfg.xml.

 

Приложение Б. Типичные паттерны утечек в 1С   

Сценарий

Типы объектов в LEAKS

Характерные вызовы в стеке

Способ исправления

Авторизация в цикле

KeyAndValue, Structure

Авторизоваться, ПолучитьТокен

Кэшировать токен

Загрузка справочника в цикле KeyAndValue СписокЭлементов, ПредопределенныеСписки Загрузить один раз перед циклом

Создание обработки в цикле

KeyAndValue, Structure

Создать(), Инициализировать

Вынести перед циклом

Накопление результатов

Array, ValueTable

Добавить, ЗагрузитьКолонку

Порционная обработка

Двоичные данные без очистки

BinaryData

ПолучитьИзВременногоХранилища

УдалитьИзВременногоХранилища

COM-объекты

COMObject

Новый COMОбъект

Явный = Неопределено

HTTP-соединения

HTTPConnection

Новый HTTPСоединение

Переиспользовать соединение

Подписки на события

Structure, KeyAndValue

ДобавитьОбработчик

УдалитьОбработчик после использования

 

 

Когда анализ показал, что утечки нет

Не каждое расследование заканчивается найденной утечкой. В нашем реальном примере анализ показал, что монотонного роста памяти между вызовами нет — Memory стабильна на уровне ~1.5 ГБ. Формально это не утечка. Но методика дала конкретный ответ: 83.7% неосвобождённых объектов создаются из-за повторной авторизации и загрузки справочника на каждый документ в очереди. Это избыточное потребление, которое можно оптимизировать.

Что он даёт:

  • Точный диагноз вместо догадок. Даже без утечки вы знаете: что потребляет память, где в коде, и можно ли оптимизировать.
  • Обоснование приоритета. «1.5 ГБ на вызов из-за авторизации в цикле по 5000 документов» — это конкретная задача с понятным эффектом, а не абстрактное «память течёт».
  • Исключение подозреваемых. Если метод проверен и Memory не растёт — он вычеркнут из списка. Можно не возвращаться.
  • Сужение круга поиска. Если память всё ещё растёт на графике мониторинга — возвращайтесь к Шагу 1.1 и берите следующий метод.

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

Вступайте в нашу телеграмм-группу Инфостарт

См. также

HighLoad оптимизация Программист 1С 8.3 1С:ERP Управление предприятием 2 Бесплатно (free)

Использование оператора «В» для полей или данных составного типа (например, Регистратор) может приводить к неочевидным проблемам.

10.11.2025    7778    ivanov660    48    

53

HighLoad оптимизация Программист 1С:Предприятие 8 1C:ERP Бесплатно (free)

Приведем примеры использования различных в динамических списках и посмотрим, почему это плохо.

18.02.2025    9809    ivanov660    39    

61

HighLoad оптимизация Технологический журнал Системный администратор Программист Бесплатно (free)

Обсудим поиск и разбор причин длительных серверных вызовов CALL, SCALL.

24.06.2024    12367    ivanov660    13    

64

HighLoad оптимизация Программист 1С:Предприятие 8 Бесплатно (free)

Метод очень медленно работает, когда параметр приемник содержит намного меньше свойств, чем источник.

06.06.2024    18819    Evg-Lylyk    73    

46

HighLoad оптимизация Программист 1С:Предприятие 8 1C:Бухгалтерия Бесплатно (free)

Анализ простого плана запроса. Оптимизация нагрузки на ЦП сервера СУБД используя типовые индексы.

13.03.2024    9193    spyke    29    

54

HighLoad оптимизация Программист 1С:Предприятие 8 Бесплатно (free)

Оказывается, в типовых конфигурациях 1С есть, что улучшить!

13.03.2024    12723    vasilev2015    22    

47
Комментарии
Подписаться на ответы Инфостарт бот Сортировка: Древо развёрнутое
Свернуть все
1. Tahallus 441 17.04.26 17:57 Сейчас в теме
Сколько по времени занимались данной проблемой ?
Интересно совокупно сколько примерно часов, и в какой период, день, неделя, месяц.
2. maraty 498 17.04.26 19:43 Сейчас в теме
(1) Сложно сказать. Часть логов у меня с января дожидалась анализа (с нескольких контуров). Изначально вообще написал на Go утилиту для анализа, но там больше было для агрегации данных. Теперь нужно найти время, переписать под методику. А по времени несколько дней + проработка шагов на реальных данных.
Для отправки сообщения требуется регистрация/авторизация