Глава 38 Журналирование (часть 1): записи, уровни и структурные поля

Ориентация главы

Журналирование — первая наблюдаемость сервиса. Ядро журнальной модели XRT — разделённая пара: Logger (xrtLogCreate, имя и порог уровня) и Sink (xrtLogSinkCreate, пункт назначения вывода) — один Logger может нести несколько Sink, один Sink переиспользуется несколькими Logger; запись, пройдя фильтр уровня Logger, транслируется на все Sink, а структурные поля (xrtLogFieldInt и другие) доходят с записью прямо до Sink, и тот потребляет их по-своему. Глава разъясняет это разделение и полный рецепт собственного Sink — фундамент для понимания пяти встроенных Sink следующей главы.

38.1引入

Три простые потребности пробивают потолок журналирования через printf. Первая: в разработке DEBUG заливает экран, в продакшене нужны только WARN и выше — фильтрация уровней не может держаться на комментировании printf и перекомпиляции. Вторая: одна и та же запись должна идти и в консоль, и в файл (в разных форматах) — пункт назначения не может быть приварен к месту вызова журнала. Третья: к сообщению request complete лучше приложить request_id=42 — при разборе «какой запрос» дороже «какое сообщение», а printf умеет только склеивать строки руками.

Три потребности указывают на одну структуру: фильтрация уровней (порог Logger), разделение вывода (трансляция Sink), структурные поля (поля идут с записью; Sink решает, как показать — текстовый Sink печатает, JSON-Sink собирает в объект fields). Дополнительные дивиденды разделения Logger/Sink разворачиваются в двух следующих главах: пять встроенных типов Sink из коробки (глава 39) и асинхронный Sink, уводящий запись на диск с горячего пути (глава 39).

38.2概念

Разделение труда Logger и Sink

Два порога, каждый на своём посту: порог Logger — политика модуля (в модуле db включён DEBUG, остальные на INFO), порог Sink — политика пункта назначения (консоль берёт только ERROR, файл принимает всё). Запись обязана пройти двое ворот, прежде чем лечь на диск, — xrtLogSinkSetLevel регулирует на ходу (операционная тема главы 39).

Собственный Sink: четыре элемента и три дисциплины

Четыре элемента xlogsinkconfig: имя (читаемое для эксплуатации), порог уровня, функция записи (сигнатура xlogresult (const xlogrecord*, ptr)), пользовательские данные (носитель цели вывода — FILE*, сокет, что угодно). Три дисциплины функции записи: запись заимствована — внутри обратного вызова ссылку удерживать нельзя (память записи принадлежит пути подачи и истекает по возвращении); семантика возвращаемого значения — XLOG_RESULT_WRITTEN/_ERROR суммируются и репортятся Logger (отказ одного Sink не валит остальные); ноль промежуточных распределений — функция записи горячего пути форматирует и пишет напрямую, не распределяя на каждую запись (прямой fprintf образца — эталон).

Структурные поля: значения идут с записью

Ценность полей — в свободе потребителя: текстовый Sink может игнорировать поля или печатать пары ключ-значение, JSON-Sink собирает их в объект fields (форма вывода json-образца главы 39), а ваш собственный Sink может отбирать только интересующие поля для тревожной сигнализации. xrtLogFieldError заслуживает отдельного упоминания — объект ошибки входит в журнал с полностью сохранённой цепочкой причин (глава 4), и при разборе «что за ошибка + почему» видно одним взглядом.

Система уровней

Пять уровней XLOG_TRACE/DEBUG/INFO/WARN/ERROR (числового возрастания). Соглашения о семантике уровней: TRACE — чертёж отладки (вплоть до «смущающе подробных» деталей), DEBUG — диагностика разработки, INFO — бизнес-веха, WARN — автоматически восстановимая аномалия, ERROR — сбой, требующий вмешательства человека. Опыт настройки порогов: в продакшене Logger на INFO, DEBUG включается по модулям — глобальный DEBUG это потоп журналов; адресное включение — вот диагностика.

38.3示例

Полная программа: собственный Sink и структурные поля

Из образца репозитория examples/logging/core/main.c — около 60 строк через весь цикл Logger/Sink/поля:

 */

#include <stdio.h>
#include <string.h>

#include <xrt.h>



/* 示例 Sink 写入函数：格式 [级别] 名字: 消息，零中间分配。 */
static xlogresult exampleWrite(
	const xlogrecord* pRecord,
	ptr pUserData
)
{
	FILE* pFile = (FILE*)pUserData;

	fprintf(
		pFile,
		"[%s] %.*s: %.*s\n",
		xrtLogLevelName(pRecord->Level),
		(int)pRecord->Logger.Size,
		pRecord->Logger.Data,
		(int)pRecord->Message.Size,
		pRecord->Message.Data
	);
	return ferror(pFile) == 0
		? XLOG_RESULT_WRITTEN
		: XLOG_RESULT_ERROR;
}



int main(void)
{
	xlogsinkconfig Config;
	xlogfield Field;
	xlogger* pLogger;
	xlogsink* pSink;

	/* Sink 配置四要素：名字 / 级别门槛 / 写入函数 / 用户数据。 */
	memset(&Config, 0, sizeof(Config));
	Config.Name = XRT_STR_LITERAL("stdout");
	Config.Level = XLOG_INFO;
	Config.Write = exampleWrite;
	Config.UserData = stdout;

	pLogger = xrtLogCreate(XRT_STR_LITERAL("example"), XLOG_DEBUG);
	pSink = xrtLogSinkCreate(&Config);
	if (
		(pLogger == NULL) || (pSink == NULL) ||
		!xrtLogAttach(pLogger, pSink)
	) {
		xrtLogSinkFree(pSink);
		xrtLogFree(pLogger);
		return 1;
	}

	/* 结构化提交：一个整数字段随记录直达 Sink。 */
	Field = xrtLogFieldInt(XRT_STR_LITERAL("request_id"), 42);
	if (
		xrtLogFields(
			pLogger,
			XLOG_INFO,
			XRT_STR_LITERAL("request complete"),
			&Field,
			1u
		) != XLOG_RESULT_WRITTEN
	) {
		xrtLogSinkFree(pSink);
		xrtLogFree(pLogger);
		return 2;
	}
	xrtLogSinkFree(pSink);
	xrtLogFree(pLogger);
	return 0;
}

Что только что произошло. (1) exampleWrite — это весь собственный Sink: fprintf пишет напрямую в формате [级别] 名字: 消息 ([уровень] имя: сообщение), xrtLogLevelName превращает перечисление в читаемое имя, ferror решает между WRITTEN и ERROR — все три дисциплины (заимствование/возвращаемое значение/ноль распределений) соблюдены. Заметьте: поля он не потребляет — request_id этим Sink проигнорирован, и это ровно воплощение тезиса «способ потребления полей решает каждый Sink сам». (2) Config.UserData = stdout — та же функция записи с stderr или файловим указателем станет другим пунктом назначения; пользовательские данные — универсальный слот Sink. (3) xrtLogCreate("example", XLOG_DEBUG) строит Logger, xrtLogSinkCreate — Sink, xrtLogAttach компонует их — сборка в три шага. (4) xrtLogFields подаёт запись с одним целочисленным полем; возвращаемое значение сверяется с WRITTEN — отказы пути подачи тоже проверяются (Sink полон или закрыт). (5) Порядок финала: сперва SinkFree, потом LogFree — Sink это ресурс по ссылке, он может быть освобождён независимо до освобождения Logger.

Полная программа: слой удобства printf

Из examples/logging/printf/main.c — удобная форма форматной подачи:

 */

#include <stdio.h>
#include <string.h>
#include <xrt.h>



/* Sink：消息已格式化完毕，直接打印即可。 */
static xlogresult exampleLogPrintfWrite(
	const xlogrecord* pRecord,
	ptr pData
)
{
	(void)pData;
	printf(
		"%.*s\n",
		(int)pRecord->Message.Size,
		pRecord->Message.Data
	);
	return XLOG_RESULT_WRITTEN;
}



int main(void)
{
	xlogsinkconfig Config;
	xlogger* pLogger;
	xlogsink* pSink;
	xlogresult Result = XLOG_RESULT_ERROR;

	memset(&Config, 0, sizeof(Config));
	Config.Name = XRT_STR_LITERAL("console");
	Config.Level = XLOG_TRACE;
	Config.Write = exampleLogPrintfWrite;
	pLogger = xrtLogCreate(XRT_STR_LITERAL("example"), XLOG_TRACE);
	pSink = xrtLogSinkCreate(&Config);
	if ( (pLogger != NULL) && (pSink != NULL) &&
		xrtLogAttach(pLogger, pSink) ) {

		/* printf 风格提交：格式化 + 记录构造一步完成。 */
		Result = xrtLogPrintf(
			pLogger,
			XLOG_INFO,
			"request=%u status=%u",
			42u,
			200u
		);
	}
	xrtLogSinkFree(pSink);
	xrtLogFree(pLogger);
	return (Result == XLOG_RESULT_WRITTEN) ? 0 : 1;
}

Что только что произошло. Подача в стиле printf (семейство xrtLogPrintf; строка формата принимает C-строки, не представления) внутри идёт через форматирование главы 25 — "request=%u status=%u" и аргументы склеиваются в текст сообщения за один шаг у входа подачи. Выбор между слоем удобства и структурными полями: поля для машинного потребления всегда через LogFields (поля хранят типы, JSON-Sink собирает их в объект); склеенные сообщения для человеческих глаз — через слой printf; при смешивании помните: «поле, вошедшее в текст сообщения, больше не структурированные данные».

38.4契约

• Заимствованная запись: функция записи Sink не удерживает ссылок на запись; представления полей также истекают с обратным вызовом.
• Возвращаемые значения: WRITTEN/ERROR суммируются Logger; отказ одного Sink не задевает остальные.
• Ноль распределений: функция записи пишет напрямую, не распределяя на каждую запись.
• Два порога: порог Logger — политика модуля, порог Sink — политика пункта назначения; запись проходит двое ворот до диска.
• Поля хранят типы: структурные поля идут через LogFields; слой printf собирает только показательный текст.
• Поле ошибки: xrtLogFieldError несёт объект ошибки главы 4 — вся цепочка причин входит в журнал.

От примеров к инженерии: три хозяина журналирования

Библиотечный код (модули, написанные для других): никакого глобального Logger — принимайте Logger, внедрённый вызывающим, или стройте независимый экземпляр по имени модуля (префиксы xrt/db, xrt/http естественно делят домены); библиотека никогда не трогает Sink напрямую (политика вывода — привилегия приложения). Прикладной сервис: сборка на старте — дерево Logger и набор Sink по конфигурации (пять встроенных типов главы 39 плюс собственный тревожный Sink), уровни читаются из переменных окружения или конфигурации, при грациозной остановке Flush и освобождение (дисциплина финала асинхронного Sink — в следующей главе). Инструментальные программы: одного консольного Logger плюс одного текстового Sink достаточно — printf, улучшенный до сорта; пять минут сборки — польза на всю жизнь. Общая дисциплина трёх хозяев: сборка журналирования концентрируется рядом с main — создание Logger, рассыпанное по бизнес-коду, — отправная точка дрейфа конфигурации.

Одна привычка: перед записью подумайте о поиске

Первый потребитель журнала — «вы, разбуженный в три часа ночи через три дня». Перед каждой записью прошепчите три вопроса: можно ли по ней локализовать проблему (есть ли корреляционное поле вроде request_id); верен ли уровень (это веха INFO или сбой ERROR); верен ли порядок величин (сколько этих записей в секунду на пике — выдержит ли диск). Записи, не прошедшие три вопроса, не пишутся вовсе: журнал, будучи написанным, — обязательство; поисковый — актив. Структурные поля — техническая опора привычки: корреляционные поля в LogFields, уровень по таблице семантик, объём наблюдается при нагрузочных тестах — статистика и ротация главы 39 — операционное продолжение привычки.

Типичные ошибки

static xlogresult slowWrite(const xlogrecord* pRecord, ptr pData)
{
	gPending = pRecord;          /* сохранено глобально "на потом" - висяче по возврату */
	return XLOG_RESULT_WRITTEN;
}

static xlogresult slowWrite(const xlogrecord* pRecord, ptr pData)
{
	queue_push(pData, pRecord);  /* очередь делает глубокую копию: поля и сообщение копируются до постановки */
	return XLOG_RESULT_WRITTEN;
}

xlogger* gLog = xrtLogCreate(XRT_STR_LITERAL("app"), XLOG_DEBUG);
/* DEBUG на все модули: каждый SQL, каждое попадание в кеш пишется на диск */

xlogger* gLog = xrtLogCreate(XRT_STR_LITERAL("app"), XLOG_INFO);
xlogger* gDbLog = xrtLogCreate(XRT_STR_LITERAL("db"), XLOG_DEBUG);
/* DEBUG только адресно на модуль db - точная диагностика, контролируемый объём */

Практические задания

Итоги