graph LR
%% УМЕРЕННО НАСЫЩЕННАЯ UI-ПАЛИТРА КУБИКОВ (Текст строго черный)
classDef core fill:#B2F5EA,stroke:#319795,stroke-width:1.5px,color:#000000,font-weight:bold;
classDef ai fill:#BEE3F8,stroke:#3182CE,stroke-width:1.5px,color:#000000,font-weight:bold;
classDef arch fill:#CBD5E0,stroke:#718096,stroke-width:1.5px,color:#000000,font-weight:bold;
classDef storage fill:#FEB2B2,stroke:#E53E3E,stroke-width:1.5px,color:#000000,font-weight:bold;
classDef obs fill:#FEEBC8,stroke:#DD6B20,stroke-width:2px,color:#000000,font-weight:bold;
%% ИНДИВИДУАЛЬНЫЕ ПАСТЕЛЬНЫЕ ПОДЛОЖКИ БОЛЬШИХ КОНТУРОВ
style Sources fill:#F7FAFC,stroke:#A0AEC0,stroke-width:1px,color:#4A5568,font-weight:bold
style Transport fill:#E6FFFA,stroke:#4FD1C5,stroke-width:1px,color:#234E52,font-weight:bold
style Analytics fill:#FFF5F5,stroke:#FC8181,stroke-width:1px,color:#9B2C2C,font-weight:bold
style CrossRef fill:#FFFAF0,stroke:#F6AD55,stroke-dasharray: 4 4,stroke-width:1px,color:#C05621,font-weight:bold
subgraph Sources ["Слой исполнения"]
GoCore["Go Core Backend<br/><i>stdout (JSON)</i>"]:::core
FastAPI["FastAPI / PM4Py Engine<br/><i>stdout (JSON)</i>"]:::ai
end
subgraph Transport ["Транспортный слой"]
Vector["Vector Agent<br/><i>VRL: .log_stream == 'process'</i>"]:::core
DiskBuffer[("Non-Blocking Disk Buffer")]:::arch
end
subgraph Analytics ["Аналитическое хранилище"]
CH_Logs[("ClickHouse DBMS<br/><i>logs.process_events</i>")]:::storage
end
subgraph CrossRef ["Внешняя связь по case_id"]
CH_Errors[("sys_observability.system_error_logs<br/><i>(Стек-трейсы сбоев)</i>")]:::obs
end
GoCore -->|log_stream: process| Vector
FastAPI -->|log_stream: process| Vector
Vector -.->|Backpressure при сбое CH| DiskBuffer
Vector -->|Batch INSERT| CH_Logs
CH_Logs -.->|JOIN / Drill-down по case_id == trace_id| CH_Errors
LOGS: Сбор логов сервисами в ClickHouse для Process Mining
В настоящее время репозиторий активно наполняется техническим контентом. Спецификация, архитектурные сценарии и справочники переводятся на два языка.
- Текущий статус локализации: Полная двуязычная версия (RU/EN) для всех внутренних разделов и системных контрактов будет развернута в ближайших релизах.
1 Сбор и структура логов Process Mining
1.1 Назначение и архитектурная роль
Process Mining восстанавливает реальную карту бизнес-процессов по логам событий (event logs), поступающим из микросервисов (Go, FastAPI) и инфраструктуры.
- Целевая база данных: logs в ClickHouse.
- Транспорт: микросервисы пишут структурированный JSON в stdout, откуда агент Vector (Non-Blocking Disk Buffering сброс на диск при недоступности СУБД) асинхронно доставляет их батчами.
- Связь с контуром ошибок: логи ошибок живут в изолированной базе sys_observability.system_error_logs. Единственная точка пересечения между ними — сквозной идентификатор (case_id в процессе равен trace_id в ошибках), что позволяет по клику на узел графа запрашивать технический контекст.
1.2 Схема данных в ClickHouse (logs.process_events)
Триада обязательных полей для построения графов (Trace Discovery):
CREATE DATABASE IF NOT EXISTS logs;
CREATE TABLE logs.process_events
(
-- 1. Сквозной идентификатор кейса (совпадает с trace_id из контура ошибок)
case_id UUID CODEC(ZSTD),
-- 2. Временная метка с микросекундами (DoubleDelta + ZSTD сжимают время)
timestamp DateTime64(6) CODEC(DoubleDelta, ZSTD),
-- 3. Активность / Шаг процесса (LowCardinality экономит RAM)
activity LowCardinality(String) CODEC(ZSTD),
-- 4. Сервис-источник и оператор
service_name LowCardinality(String) CODEC(ZSTD),
operator_id LowCardinality(String) CODEC(ZSTD),
-- 5. Легковесный JSON с бизнес-атрибутами (до 5–10 ключей)
attributes_json String CODEC(ZSTD),
INDEX idx_case_id case_id TYPE bloom_filter(0.01) GRANULARITY 1
)
ENGINE = MergeTree()
PARTITION BY toYYYYMM(timestamp)
ORDER BY (case_id, timestamp)
TTL timestamp + INTERVAL 365 DAY
SETTINGS index_granularity = 8192;
1.3 Техническая расшифровка оптимизаций СУБД
- CODEC(DoubleDelta, ZSTD) для timestamp: превращает последовательные метки времени в малые дельты, сжимая временной ряд в разы.
- LowCardinality(String) для activity и service_name: заменяет повторяющиеся названия шагов на числовые индексы, ускоряя GROUP BY и построение DFG-графов.
- bloom_filter(0.01) на case_id: дает быстрый точечный поиск конкретной трассы среди миллиардов событий без полного сканирования диска.
- PARTITION BY toYYYYMM + TTL 365 DAY: годовое хранение истории с мгновенным удалением старых партиций целиком.
- index_granularity = 8192: разреженный индекс в оперативной памяти.
1.4 Конфигурация маршрутизации в Vector (VRL)
Правило фильтрации потока из stdout для записи в базу logs:
[transforms.route_process_logs]
type = "route"
inputs = ["docker_logs"]
route.pm_events = '.log_stream == "process"'
[sinks.clickhouse_process_events]
type = "clickhouse"
inputs = ["route_process_logs.pm_events"]
database = "logs"
table = "process_events"
# batch.max_events = 1000
# batch.timeout_secs = 2
1.5 Требования к качеству данных (Data Quality Contract)
- Синхронизация времени: строгий UTC с микросекундами (DateTime64(6)). Дрейф часов выше 500 мс ломает порядок переходов в алгоритмах майнинга.
- Идемпотентность: ретраи gRPC/Kafka дедуплицируются на уровне витрин через ROW_NUMBER() OVER (PARTITION BY case_id, activity ORDER BY timestamp ASC).
- Запрет тяжелых тел: в attributes_json запрещено складывать imageBase64, бинарники и полные payloads.
1.6 Архитектура потока логирования Process Mining
2 Правила логирования событий для Process Mining
2.1 Жизненный цикл события: Логировать «Старт» и «Финиш» (Performance Mining)
Если сервис логирует только одну точку: log.Info(“Событие обработано”), Process Mining сможет построить только граф переходов, но он будет абсолютно слеп к задержкам. Мы никогда не узнаем, сколько задача лежала в очереди Kafka или сколько миллисекунд Whisper транскрибировал аудио.
Как правильно:
Каждая атомарная операция на микро-уровне должна генерировать два события в ClickHouse: статус START и статус COMPLETE.
Посмотрим на сервис FoodIngestionService Consumer со второй схемы. Когда он вычитывает пачку событий из топика purchase-events и пишет их в Business DB, внутри Go-кода это должно логироваться так:
// 1. Задача извлечена из Kafka — фиксируем НАЧАЛО обработки на микро-уровне
sendToClickHouse(EventLog{
CaseID: orderID,
ActivityName: "Ingestion_Consumer_Write_DB",
Stage: "START", // Токен зашел в узел
Timestamp: time.Now(),
})
// ... здесь идет сама транзакция записи в Business DB ...
// 2. Транзакция успешно завершена — фиксируем КОНЕЦ обработки
sendToClickHouse(EventLog{
CaseID: orderID,
ActivityName: "Ingestion_Consumer_Write_DB",
Stage: "COMPLETE", // Токен вышел из узла
Timestamp: time.Now(),
})
Что это дает в PM4Py: Библиотека берет Timestamp для START и COMPLETE одного и того же действия.
- Разница между ними — это чистая скорость работы БД.
- Разница между COMPLETE предыдущего сервиса-издателя (Publisher) и START текущего потребителя (Consumer) — это чистое время простоя сообщения внутри топиков Kafka! Мы видим лаг очередей без установки сложных внешних систем мониторинга Kafka.
2.2 Маппинг «Сквозного контекста» (Борьба с процессами-зомби)
Чтобы связать действия мобильного приложения, брокера Kafka и ИИ-контура в единую цепочку, в ClickHouse должен лететь сквозной идентификатор трека. Но на второй схеме есть независимые топики: purchase-events, cook-events, waste-events. У них внутри могут быть свои локальные ID.
Как правильно:
Архитектура должна поддерживать паттерн Distributed Context Propagation (Распространение контекста), аналогично тому, как это делается в OpenTelemetry, но в терминах бизнес-логики:
- Когда мобильный клиент вызывает gRPC TrackCooking, бэкенд на Go генерирует уникальный root_trace_id (или session_id).
- Этот ID упаковывается в заголовки (Headers) сообщения Kafka при отправке в топик cook-events.
- Когда FoodIngestionService Consumer вычитывает это событие, он обязан достать этот root_trace_id из заголовка и записать его в колонку case_id в ClickHouse.
Как это ловит «Процессы-зомби»:
Если пользователь оборвал сессию на мобилке, а фоновый воркер food-receipt-processor продолжает крутить тяжелый OCR чека, этот воркер все равно запишет в ClickHouse логи со статусами START под тем самым root_trace_id.
Python-воркер запустит Token Replay, увидит, что по этому root_trace_id верхнеуровневый процесс давно закрыт, а в глубине ИИ-контура продолжают сыпаться события START без закрывающих COMPLETE. Метрика застрявших токенов (remaining) локализует место утечки ресурсов.
2.3 Логирование «Попытки» (Детекция каскадных штормов ретраев)
Если внутри вашего gRPC RegisterStoreReceipt (на второй схеме) настроена политика повторных попыток (HTTP/gRPC Retries) при сбое связи с процессором чеков, каждый ретрай должен быть залогирован как отдельная микро-активность с указанием номера попытки.
Как правильно:
Вместо того чтобы молча крутить цикл повторов внутри Go-кода, пишите в ClickHouse структурированное имя шага:
- RegisterReceipt_Attempt_1 -> FAILED
- RegisterReceipt_Attempt_2 -> FAILED
- RegisterReceipt_Attempt_3 -> COMPLETE
Что это дает в PM4Py:
На частотном графе процессов бизнес-аналитики и архитекторы увидят не просто одну стрелочку «Регистрация чека», а динамическую спираль (петлю), на которой будет написано: «Шаг повторен 4500 раз за сутки». Это станет главным легитимным основанием для проведения рефакторинга и внедрения паттерна Circuit Breaker, чтобы остановить бессмысленное каскадное выжигание ресурсов Docker-хоста.
2.4 Стандарт лога для ClickHouse
Чтобы выжать максимум из Process Mining на микро-уровне, структура записи в ClickHouse, формируемая вашими Go-сервисами, должна выглядеть так:
{
"case_id": "root_trace_uuid_12345", // Сквозной ID транзакции (общий для мобилки, Kafka и БД)
"activity_name": "gRPC_TrackCooking_DB_Write", // Имя конкретного микро-узла бэкенда
"event_stage": "START", // START или COMPLETE (для Performance Mining)
"event_timestamp": "2026-10-09T12:00:05.123456Z", // Время с точностью до микросекунд (Time-Smoothing)
"user_role": "User", // Кто запустил (User / Симулятор)
"attributes": { // Контекст для расследования
"kafka_topic": "cook-events",
"retry_number": "0",
"db_table": "business_fridge_inventory"
}
}
2.5 Пример плоской таблицы фактов (Event Log) в ClickHouse
Чтобы процесс из BPMN-схемы можно было динамически разложить на сеть Петри в Python необходима таблица фактов скажем business_analytics.simulation_event_logs где каждая строчка в ClickHouse — это след (событие), оставленный бэкендом на Go при прохождении конкретного шага схемы. Связующим звеном всех шагов (Object-Centric контекстом) будет выступать, например, case_id.
2.5.1 Вариант: Идеальный лог (Happy Path — Fitness Score = 1.0)
В этом случае система отработала строго по стрелочкам: от шага 1 до шага 10, включая асингулярную запись шага 12-13.
В ClickHouse для одного успешного заказа (case_id = “order_req_999”) запишутся следующие строки:
| case_id | activity_name | event_timestamp | scenario_id | user_role | product_name | attributes |
|---|---|---|---|---|---|---|
order_req_999 |
|
2026-10-09 12:00:00.001000 |
partner_integration | User | Список продуктов | {"partner_id": "shop_44"} |
order_req_999 |
|
2026-10-09 12:00:00.005000 |
partner_integration | User | — | {"auth_status": "OK"} |
order_req_999 |
|
2026-10-09 12:00:00.008000 |
partner_integration | User | — | {"schema_version": "v2"} |
order_req_999 |
|
2026-10-09 12:00:00.015000 |
partner_integration | User | Молоко, Хлеб | {"db_status": "COMMITTED"} |
order_req_999 |
12-13. Зафиксировать шаг в Event Log | 2026-10-09 12:00:00.022000 |
partner_integration | User | — | {"audit_pool": "B2B_Partners"} |
order_req_999 |
|
2026-10-09 12:00:00.025000 |
partner_integration | User | — | {"http_status": "200_Trigger"} |
order_req_999 |
|
2026-10-09 12:00:00.095000 |
partner_integration | User | — | {"delivery_status": "SUCCESS"} |
Магия PM4Py: Алгоритм Token Replay возьмет эти строки, упорядочит их по времени (event_timestamp), протащит токен по всем позициям и скажет: «Ошибок нет, процесс выполнен на 100%»
2.5.2 Вариант: Лог со сбоем (Критический баг — Fitness Score < 1.0)
А теперь представим ситуацию из пункта [18.1] (выявление логических багов). Бэкенд на Go успешно выполнил шаг 8 (зачислил продукты в базу), вызвал Webhook (шаг 9), но асинхронная горутина пуша в пул аудита упала из-за сетевого таймаута. В ClickHouse для заказа order_req_err_777 запишется вот такой лог:
| case_id | activity_name | event_timestamp | scenario_id | user_role | attributes |
|---|---|---|---|---|---|
order_req_err_777 |
|
2026-10-09 12:15:00.001000 |
partner_integration | User | {"partner_id": "shop_44"} |
order_req_err_777 |
|
2026-10-09 12:15:00.003000 |
partner_integration | User | {"auth_status": "OK"} |
order_req_err_777 |
|
2026-10-09 12:15:00.006000 |
partner_integration | User | {"schema_version": "v2"} |
order_req_err_777 |
|
2026-10-09 12:15:00.012000 |
partner_integration | User | {"db_status": "COMMITTED"} |
| [КРИТИЧЕСКИЙ СБОЙ] | СТРОКА С ШАГОМ 12-13 ОТСУТСТВУЕТ | ГОРУТИНА УПАЛА | — | — | — |
order_req_err_777 |
|
2026-10-09 12:15:00.018000 |
partner_integration | User | {"http_status": "200_Trigger"} |
order_req_err_777 |
|
2026-10-09 12:15:00.050000 |
partner_integration | User | {"delivery_status": "SUCCESS"} |
3 Примеры логирования и двойного логирования
3.1 как в коде будут одновременно логироваться ошибки и процесс майнинг?
В коде приложений это реализуется через паттерн Dual-Stream Logging (Двухпотоковое логирование). Внутри бизнес-метода разработчик использует два разных логгера, которые отправляют данные в разные каналы. Поскольку мы выяснили, что логи ошибок и события Process Mining имеют разную структуру и назначение, они разделяются прямо в коде.
3.2 Пример Go-кода (Dual-Stream In Action)
package main
import (
"context"
"log/slog"
"os"
"time"
)
// Инициализируем два разных логгера
var (
// Stream 1: Системный логгер ошибок (Пишет в stdout для Vector)
sysLogger = slog.New(slog.NewJSONHandler(os.Stdout, nil))
// Stream 2: Логгер бизнес-событий для Process Mining (Отправляет напрямую в ClickHouse или специальный файл)
pmLogger = slog.New(slog.NewJSONHandler(os.Stderr, nil)) // Или кастомный коннектор к ClickHouse/Kafka
)
func ProcessReceiptTransaction(ctx context.Context, txID string, userID string, imageBase64 string) {
// --- ТОЧКА 1: Фиксируем начало процесса для Process Mining ---
pmLogger.Info("Process_Mining_Event",
slog.String("case_id", txID), // Сквозной ID сессии
slog.Time("timestamp", time.Now()), // Наносекунды
slog.String("activity", "Receipt_OCR_Started"), // Имя шага
slog.String("operator", userID),
)
// Имитируем запрос к ИИ-шлюзу на FastAPI
err := callAiVisionGateway(imageBase64)
// --- ТОЧКА 2: Ветвление логики (Ошибка или Успех) ---
if err != nil {
// КЕЙС А: Произошел технический сбой (ИИ завис)
// 1. Пишем в лог ошибок для разработчиков (Observability)
sysLogger.Error("AI pipeline execution failed",
slog.Time("timestamp", time.Now()),
slog.String("trace_id", txID),
slog.String("canonical_code", "AI_VISION_TIMEOUT"),
slog.String("message", err.Error()),
slog.String("stack_trace", "main.go:line 45... internal timeout"),
)
// 2. Фиксируем аварийный шаг в Process Mining, чтобы аналитики видели отклонение от графа
pmLogger.Info("Process_Mining_Event",
slog.String("case_id", txID),
slog.Time("timestamp", time.Now()),
slog.String("activity", "Receipt_OCR_Failed"),
slog.String("operator", userID),
)
return
}
// КЕЙС Б: Всё прошло успешно
// Фиксируем успешный шаг бизнес-процесса
pmLogger.Info("Process_Mining_Event",
slog.String("case_id", txID),
slog.Time("timestamp", time.Now()),
slog.String("activity", "Receipt_OCR_Success"), // Тот самый успешный шаг!
slog.String("operator", userID),
)
}
func callAiVisionGateway(img string) error {
// Логика вызова FastAPI
return nil
}
3.3 Приложение: Объединенный пример реализации на Go (slog)
В реальном микросервисе обработчик транзакции вызывает оба логгера (system и process), сохраняя единый trace_id / case_id для сквозного аудита. Агент Vector по полю log_stream разложит этот вывод по разным таблицам ClickHouse.
package main
import (
"context"
"errors"
"fmt"
"log/slog"
"os"
"time"
"://github.com"
)
// Единый JSON-обработчик в stdout, маршрутизируемый Vector
var logger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
Level: slog.LevelInfo,
}))
// LogSystemError пишет в sys_observability.system_error_logs
func LogSystemError(ctx context.Context, service, traceID, canonicalCode, msg, stack string, observabilityJSON string) {
logger.Error("system_exception",
slog.String("log_stream", "system"),
slog.Time("timestamp", time.Now().UTC()),
slog.String("service_name", service),
slog.String("trace_id", traceID),
slog.String("canonical_code", canonicalCode),
slog.String("level", "ERROR"),
slog.String("message", msg),
slog.String("stack_trace", stack),
slog.String("observability_json", observabilityJSON),
)
}
// LogProcessEvent пишет в logs.process_events (case_id == trace_id)
func LogProcessEvent(ctx context.Context, service, caseID, activity, operatorID string, attrsJSON string) {
if attrsJSON == "" {
attrsJSON = "null"
}
logger.Info("process_transition",
slog.String("log_stream", "process"),
slog.Time("timestamp", time.Now().UTC()),
slog.String("service_name", service),
slog.String("case_id", caseID),
slog.String("activity", activity),
slog.String("operator_id", operatorID),
slog.String("attributes_json", attrsJSON),
)
}
// Пример бизнес-метода с Dual-Stream Logging
func ProcessReceiptTransaction(ctx context.Context, txID uuid.UUID, userID string, imageBase64 string) error {
service := "receipt-processor"
idStr := txID.String()
// 1. Фиксируем старт шага в Process Mining
LogProcessEvent(ctx, service, idStr, "Receipt_OCR_Started", userID, `{"channel": "mobile"}`)
// 2. Имитация вызова внешнего ИИ-шлюза
err := callAiVisionGateway(imageBase64)
if err != nil {
// А) Логируем технический сбой в контур Observability
stack := fmt.Sprintf("ai_client.go:142 -> %v", err)
obsJSON := `{"metric": "ai_timeout", "labels": {"service": "fastapi", "model": "whisper"}}`
LogSystemError(ctx, service, idStr, "AI_WHISPER_TIMEOUT", err.Error(), stack, obsJSON)
// Б) Фиксируем аварийный шаг в Process Mining (для построения развилки на графе)
LogProcessEvent(ctx, service, idStr, "Receipt_OCR_Failed", userID, `{"error_code": "AI_WHISPER_TIMEOUT"}`)
return err
}
// 3. Фиксируем успешный шаг в Process Mining
LogProcessEvent(ctx, service, idStr, "Receipt_OCR_Success", userID, `{"confidence": 0.98}`)
return nil
}
func callAiVisionGateway(img string) error {
// Имитация таймаута
return errors.New("CUDA alloc timeout in whisper_model.py")
}
func main() {
ctx := context.Background()
txID := uuid.New()
_ = ProcessReceiptTransaction(ctx, txID, "operator_42", "base64_data...")
}
3.4 Пример реализации на Go (slog)
package main
import (
"context"
"log/slog"
"os"
"time"
)
var pmLogger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
Level: slog.LevelInfo,
}))
// LogProcessEvent фиксирует шаг бизнес-процесса в строгом контракте
func LogProcessEvent(ctx context.Context, service, caseID, activity, operator string, attrs map[string]string) {
// Конвертируем attrs в простой JSON или оставляем плоскими полями
attrJSON := "null"
if len(attrs) > 0 {
// Упрощенная сериализация для примера
attrJSON = `{"key": "value"}`
}
pmLogger.Info("process_event",
slog.String("log_stream", "process"),
slog.Time("timestamp", time.Now().UTC()),
slog.String("service_name", service),
slog.String("case_id", caseID),
slog.String("activity", activity),
slog.String("operator_id", operator),
slog.String("attributes_json", attrJSON),
)
}
func ProcessReceiptTransaction(ctx context.Context, txID string, userID string) {
service := "receipt-processor"
// Шаг 1: Старт
LogProcessEvent(ctx, service, txID, "Receipt_OCR_Started", userID, map[string]string{
"channel": "mobile_app",
})
// Бизнес-логика...
success := true
// Шаг 2: Завершение
if success {
LogProcessEvent(ctx, service, txID, "Receipt_OCR_Success", userID, nil)
} else {
LogProcessEvent(ctx, service, txID, "Receipt_OCR_Failed", userID, map[string]string{
"reason": "ocr_low_confidence",
})
}
}
3.5 Архитектурный разбор: Как это работает одновременно?
Разделение на уровне полей лога:
- Когда отрабатывает sysLogger.Error, он генерирует плоскую техническую структуру с полями canonical_code, trace_id и stack_trace. Агент Vector отлавливает её и складывает в таблицу sys_observability.system_error_logs.
- Когда срабатывает pmLogger.Info, он всегда генерирует фиксированный набор бизнес-метрик, необходимых для журналов событий: case_id, timestamp и activity [Журнал событий процессов]. Vector или специализированный клиент ClickHouse направляет это в таблицу logs.process_events [Единое хранилище логов ClickHouse].
Полный контроль над графом процесса:
Благодаря такому подходу аналитик в Process Mining увидит на графе полноценную развилку:
• Путь А: Receipt_OCR_Started → Receipt_OCR_Success (Идеальный процесс).
• Путь Б: Receipt_OCR_Started → Receipt_OCR_Failed (Процесс с ошибкой).
При этом инженеры, расследуя Путь Б, откроют соседнюю таблицу ошибок в ClickHouse, найдут там соответствующий trace_id и мгновенно увидят сырой Python-стэк трейс, из-за которого ИИ-модель упала.