【6】Strongswan bus 与 logger-优快云博客

本文链接：https://blog.youkuaiyun.com/jingshaoyou/article/details/146420483

 //Logger 接口，侦听总线上的日志事件。对 bus_t.log（） 的调用与对其他函数的调用分开处理。Logger 函数可以由多个线程并发调用。此外，不会阻止递归调用，可能导致递归日志消息的 Logger 负责避免无限循环。log（） 和 vlog（） 方法都是可选的实现。对于许多 logger，使用 log（） 可能会更快，因为所有 logger 的 printf（） 格式替换只进行一次。
 //父类
struct logger_t {

	/**
	 * 记录调试消息。
	 *
	 * @param group		信号种类 (up, down, rekeyed, ...)
	 * @param level		信号的详细级别（非OS的信号）
	 * @param thread	引发此信号的线程的 ID
	 * @param ike_sa	事件相关的IKE_SA 
	 * @param message	日志消息
	 */
	void (*log)(logger_t *this, debug_t group, level_t level, int thread,
				ike_sa_t *ike_sa, const char *message);

	/**
	 * 格式化记录调试消息
	 *
	 * @param group		kind of the signal (up, down, rekeyed, ...)
	 * @param level		verbosity level of the signal
	 * @param thread	ID of the thread raised this signal
	 * @param ike_sa	IKE_SA associated to the event
	 * @param fmt		log message format string
	 * @param args		variable arguments to format string
	 */
	void (*vlog)(logger_t *this, debug_t group, level_t level, int thread,
				 ike_sa_t *ike_sa, const char *fmt, va_list args);

	/**
	 * 获取调试组所需的日志级别。这在注册期间调用。如果所需的日志级别已更改，请向总线重新注册 Logger。
	 *
	 * @param group		debug group
	 * @return			max level to log (0..4) or -1 for none (see debug.h)
	 */
	level_t (*get_level)(logger_t *this, debug_t group);
};

/**
 * Logger to files which implements listener_t.实现listener_t实例时其中的输入日志到文件
 */
 //子类
struct file_logger_t {

	/**
	 * 实现logger_t 父类接口。
	 */
	logger_t logger;

	/**
	 * 设置 debug 组的 loglevel。
	 *
	 * @param group		debug group to set
	 * @param level		max level to log (0..4)
	 */
	void (*set_level) (file_logger_t *this, debug_t group, level_t level);

	/**
	 * 设置此 Logger 使用的选项
	 *
	 * @param options	options for this file logger
	 */
	void (*set_options) (file_logger_t *this, file_logger_options_t *options);

	/**
	 * 根据给定的参数打开（或重新打开）日志文件。
	 *
	 * @param flush_line	TRUE to flush buffers after every logged line
	 * @param append		FALSE to overwrite an existing file, TRUE to append
	 */
	void (*open) (file_logger_t *this, bool flush_line, bool append);

	/**
	 * 销毁 file_logger_t 对象。
	 */
	void (*destroy) (file_logger_t *this);
};

/**
 * Logger 使用的选项.
 */
struct file_logger_options_t {
	/** Format of timestamp prefix, as in strftime(), cloned */
	char *time_format;
	/** Optinoal precision suffix for timestamp */
	file_logger_time_precision_t time_precision;
	/** Prefix the name/unique ID of the IKE_SA */
	bool ike_name;
	/** Include the log level in the message */
	bool log_level;
	/** Log as JSON objects */
	bool json;
};

/**
 * Private data of a file_logger_t object
 */
 //孙类
struct private_file_logger_t {

	/**
	 * 子类接口.
	 */
	file_logger_t public;

	/**
	 * 文件名
	 */
	char *filename;

	/**
	 * 当前输出文件句柄
	 */
	FILE *out;

	/**
	 * 一行一刷新
	 */
	bool flush_line;

	/**
	 * 每个组要记录的最大级别
	 */
	level_t levels[DBG_MAX];

	/**
	 * strftime() format of time prefix, if any
	 */
	char *time_format;

	/**
	 * Add milliseconds/microseconds after the time string
	 */
	file_logger_time_precision_t time_precision;

	/**
	 * Print the name/# of the IKE_SA?
	 */
	bool ike_name;

	/**
	 * Print the log level
	 */
	bool log_level;

	/**
	 * Print log messages as JSON objects
	 */
	bool json;

	/**
	 * 互斥锁，以确保多行日志消息不会被撕裂
	 */
	mutex_t *mutex;

	/**
	 * Lock to read/write options (FD, levels, time_format, etc.)
	 */
	rwlock_t *lock;
};

//打开文件
METHOD(file_logger_t, open_, void,
	private_file_logger_t *this, bool flush_line, bool append)
{
	FILE *file;

	if (streq(this->filename, "stderr"))
	{
		file = stderr;
	}
	else if (streq(this->filename, "stdout"))
	{
		file = stdout;
	}
	else
	{
		file = fopen(this->filename, append ? "a" : "w");
		if (file == NULL)
		{
			DBG1(DBG_DMN, "opening file %s for logging failed: %s",
				 this->filename, strerror(errno));
			return;
		}
#ifdef HAVE_CHOWN
		//提权
		if (lib->caps->check(lib->caps, CAP_CHOWN))
		{
			if (chown(this->filename, lib->caps->get_uid(lib->caps),
					  lib->caps->get_gid(lib->caps)) != 0)
			{
				DBG1(DBG_NET, "changing owner/group for '%s' failed: %s",
					 this->filename, strerror(errno));
			}
		}
		else
		{
			if (chown(this->filename, -1, lib->caps->get_gid(lib->caps)) != 0)
			{
				DBG1(DBG_NET, "changing group for '%s' failed: %s",
					 this->filename, strerror(errno));
			}
		}
#endif /* HAVE_CHOWN */
#ifdef HAVE_SETLINEBUF
		if (flush_line)
		{
			//setlinebuf 函数将指定流 stream 设置为行缓冲模式.当程序遇到换行符 \ 时，数据就会被写入磁盘或从磁盘读取。
			//提高程序的交互性，每次遇到换行符数据立即输出，方便查看。
			setlinebuf(file);
		}
#endif /* HAVE_SETLINEBUF */
	}
	this->lock->write_lock(this->lock);
	close_file(this);
	this->out = file;
	this->flush_line = flush_line;
	this->lock->unlock(this->lock);
}

//
METHOD(logger_t, log_, void,
	private_file_logger_t *this, debug_t group, level_t level, int thread,
	ike_sa_t* ike_sa, const char *message)
{
	char groupstr[5], timestr[128];
	char idstr[11] = "", namestr[128] = "", nameidstr[142] = "";
	const char *current = message, *next = NULL;
	struct tm tm;
	timeval_t tv;
	time_t s;
	size_t time_len;

	//
	this->lock->read_lock(this->lock);
	if (!this->out)
	{	/* file is not open */
		this->lock->unlock(this->lock);
		return;
	}

	//读写锁保护读/写选项（FD、级别、time_format 等）
	if (this->time_format)
	{
		//将时间结构转换为字符串
		gettimeofday(&tv, NULL);
		s = tv.tv_sec;
		localtime_r(&s, &tm);
		time_len = strftime(timestr, sizeof(timestr), this->time_format, &tm);

		if (this->time_precision == FILE_LOGGER_TIME_PRECISION_US &&
			sizeof(timestr) - time_len > 7)
		{
			snprintf(&timestr[time_len], sizeof(timestr)-time_len, ".%06d",
					 tv.tv_usec);
		}
		else if (this->time_precision == FILE_LOGGER_TIME_PRECISION_MS &&
				 sizeof(timestr) - time_len > 4)
		{
			snprintf(&timestr[time_len], sizeof(timestr)-time_len, ".%03u",
					 tv.tv_usec / 1000);
		}
	}

	//ike_sa name
	if (this->ike_name && ike_sa)
	{
		snprintf(idstr, sizeof(idstr), "%u", ike_sa->get_unique_id(ike_sa));
		if (ike_sa->get_peer_cfg(ike_sa))
		{
			snprintf(namestr, sizeof(namestr), "%s", ike_sa->get_name(ike_sa));
		}
	}

	//互斥锁，保护以确保多行日志消息不会被撕裂
	this->mutex->lock(this->mutex);
	if (this->json)
	{
		fprintf(this->out, "{");
		if (this->time_format)
		{
			fprintf(this->out, "\"time\":\"%s\",", timestr);
		}
		fprintf(this->out, "\"thread\":%u,\"group\":\"%N\",\"level\":%u,",
				thread, debug_names, group, level);
		if (idstr[0])
		{
			fprintf(this->out, "\"ikesa-uniqueid\":\"%s\",", idstr);
		}
		if (namestr[0])
		{
			fprintf(this->out, "\"ikesa-name\":\"%s\",", namestr);
		}
		fprintf(this->out, "\"msg\":\"");
		/* replace some characters incompatible with JSON strings */
		for (next = current; *next; next++)
		{
			const char *esc;

			switch (*next)
			{
				case '\n':
					esc = "\\n";
					break;
				case '\\':
					esc = "\\\\";
					break;
				case '"':
					esc = "\\\"";
					break;
				default:
					continue;
			}
			fprintf(this->out, "%.*s%s", (int)(next - current), current, esc);
			current = next + 1;
		}
		fprintf(this->out, "%s\"}\n", current);
	}
	else
	{
		if (this->log_level)
		{
			snprintf(groupstr, sizeof(groupstr), "%N%d", debug_names, group,
					 level);
		}
		else
		{
			snprintf(groupstr, sizeof(groupstr), "%N", debug_names, group);
		}
		if (idstr[0])
		{
			snprintf(nameidstr, sizeof(nameidstr), " <%s%s%s>", namestr,
					 namestr[0] ? "|" : "", idstr);
		}
		/* prepend the prefix in front of every line */
		while (TRUE)
		{
			next = strchr(current, '\n');
			if (this->time_format)
			{
				fprintf(this->out, "%s %.2d[%s]%s ",
						timestr, thread, groupstr, nameidstr);
			}
			else
			{
				fprintf(this->out, "%.2d[%s]%s ",
						thread, groupstr, nameidstr);
			}
			if (!next)
			{
				fprintf(this->out, "%s\n", current);
				break;
			}
			fprintf(this->out, "%.*s\n", (int)(next - current), current);
			current = next + 1;
		}
	}
#ifndef HAVE_SETLINEBUF
	if (this->flush_line)
	{
		fflush(this->out);
	}
#endif /* !HAVE_SETLINEBUF */
	this->mutex->unlock(this->mutex);
	this->lock->unlock(this->lock);
}

file_logger_t *file_logger_create(char *filename)
{
	private_file_logger_t *this;

	INIT(this,
		.public = {
			.logger = {
				.log = _log_,
				.get_level = _get_level,
			},
			.set_level = _set_level,
			.set_options = _set_options,
			.open = _open_,
			.destroy = _destroy,
		},
		.filename = strdup(filename),
		.mutex = mutex_create(MUTEX_TYPE_DEFAULT),
		.lock = rwlock_create(RWLOCK_TYPE_DEFAULT),
	);

	set_level(this, DBG_ANY, LEVEL_SILENT);

	return &this->public;
}

以下是bus数据结构

struct bus_t {
	......
	/**
	 * 向总线注册一个 Logger。
	 * logger记录器是被动的;发出事件的线程处理 Logger 例程函数。此例程可由多个线程并发调用。不会阻止递归调用，因此可能导致递归调用的 Logger 负责避免无限循环。 ...
	 * 在注册期间，将对所有日志组调用 get_level（），并注册记录器以接收请求的日志级别> LEVEL_SILENT且其级别低于或等于请求的级别的组的日志消息。
	 * 要更新已注册的日志级别，请使用同一 logger 再次调用 add_logger 并从 get_level（） 返回新级别。
	 *
	 * @param logger	logger to register.
	 */
	void (*add_logger) (bus_t *this, logger_t *logger);

	/**
	 * 从 bus 取消注册 logger。
	 *
	 * @param logger	logger to unregister.
	 */
	void (*remove_logger) (bus_t *this, logger_t *logger);
	......
	/**
	 * 向总线发送日志消息。
	 * 格式字符串指定带有 printf（） 之类的变量参数列表的附加信息或错误消息。
	 * Use the DBG() macros.  如下代码：
	 *
	 * @param group		debugging group
	 * @param level		verbosity level of the signal
	 * @param format	printf() style format string
	 * @param ...		printf() style argument list
	 */
	void (*log)(bus_t *this, debug_t group, level_t level, char* format, ...);
	
	/**
	 * 使用 va_list 参数向总线发送日志消息.与 bus_t.log（） 相同，但使用va_list参数列表.
	 *
	 * @param group		kind of the signal (up, down, rekeyed, ...)
	 * @param level		verbosity level of the signal
	 * @param format	printf() style format string
	 * @param args		va_list arguments
	 */
	void (*vlog)(bus_t *this, debug_t group, level_t level,
				 char* format, va_list args);
	......
}

//日志组
/**
 * Debug message group.
 */
enum debug_t {
	/** daemon specific */
	DBG_DMN,
	/** IKE_SA_MANAGER */
	DBG_MGR,
	/** IKE_SA */
	DBG_IKE,
	/** CHILD_SA */
	DBG_CHD,
	/** job processing */
	DBG_JOB,
	/** configuration backends */
	DBG_CFG,
	/** kernel interface */
	DBG_KNL,
	/** networking/sockets */
	DBG_NET,
	/** low-level encoding/decoding (ASN.1, X.509 etc.) */
	DBG_ASN,
	/** message encoding/decoding */
	DBG_ENC,
	/** trusted network connect */
	DBG_TNC,
	/** integrity measurement client */
	DBG_IMC,
	/** integrity measurement verifier */
	DBG_IMV,
	/** platform trust service */
	DBG_PTS,
	/** libtls */
	DBG_TLS,
	/** applications other than daemons */
	DBG_APP,
	/** libipsec */
	DBG_ESP,
	/** libstrongswan */
	DBG_LIB,
	/** number of groups */
	DBG_MAX,
	/** pseudo group with all groups */
	DBG_ANY = DBG_MAX,
};

//DBG() macros 对应上面的结构体成员log，程序需要打印日志时调用这些宏，向总线发送日志消息。
#ifndef DEBUG_LEVEL
# define DEBUG_LEVEL 4
#endif /* DEBUG_LEVEL */

#if DEBUG_LEVEL >= 0
#define DBG0(group, format, ...) charon->bus->log(charon->bus, group, 0, format, ##__VA_ARGS__)
#endif /* DEBUG_LEVEL >= 0 */
#if DEBUG_LEVEL >= 1
#define DBG1(group, format, ...) charon->bus->log(charon->bus, group, 1, format, ##__VA_ARGS__)
#endif /* DEBUG_LEVEL >= 1 */
#if DEBUG_LEVEL >= 2
#define DBG2(group, format, ...) charon->bus->log(charon->bus, group, 2, format, ##__VA_ARGS__)
#endif /* DEBUG_LEVEL >= 2 */
#if DEBUG_LEVEL >= 3
#define DBG3(group, format, ...) charon->bus->log(charon->bus, group, 3, format, ##__VA_ARGS__)
#endif /* DEBUG_LEVEL >= 3 */
#if DEBUG_LEVEL >= 4
#define DBG4(group, format, ...) charon->bus->log(charon->bus, group, 4, format, ##__VA_ARGS__)
#endif /* DEBUG_LEVEL >= 4 */

METHOD(bus_t, vlog, void,
	private_bus_t *this, debug_t group, level_t level,
	char* format, va_list args)
{
	linked_list_t *loggers;
	log_data_t data;

	/* 注意：这不是 100% 线程安全的，这里只是因为它对性能至关重要。因此，对于这种特殊情况，我们忽略了以下两个问题：
	1） 如果另一个线程同时增加日志级别或注册新的 Logger，我们可能会错过一些日志消息。
	2） 我们可能必须获取下面的读锁，即使由于另一个线程同时取消注册 Logger 或降低级别而不再需要它。*/
	if (skip_level(&this->max_level[group], level) &&
		skip_level(&this->max_vlevel[group], level))
	{
		return;
	}

	this->log_lock->read_lock(this->log_lock);
	loggers = this->loggers[group];

	if (this->max_level[group] >= level)
	{
		char buf[1024];
		ssize_t len;

		data.ike_sa = this->thread_sa->get(this->thread_sa);
		data.thread = thread_current_id();
		data.group = group;
		data.level = level;
		data.message = buf;

		va_copy(data.args, args);
		len = vsnprintf(data.message, sizeof(buf), format, data.args);
		va_end(data.args);
		if (len >= sizeof(buf))
		{
			len++;
			data.message = malloc(len);
			va_copy(data.args, args);
			len = vsnprintf(data.message, len, format, data.args);
			va_end(data.args);
		}
		if (len > 0)
		{
			//比如group对应的组，如group为DBG_IKE时针对DBG_IKE这个组对应的loggers linked_list_t，
			//loggers linked_list_t为每个日志组的已注册记录器列表log_entry_t。Loggers 按日志级别降序排序。
			//遍历该loggers linked_list_t，执行log_cb函数，数据为data  一看注册，二看执行。
			loggers->invoke_function(loggers, log_cb, &data);
		}
		if (data.message != buf)
		{
			free(data.message);
		}
	}
	if (this->max_vlevel[group] >= level)
	{
		data.ike_sa = this->thread_sa->get(this->thread_sa);
		data.thread = thread_current_id();
		data.group = group;
		data.level = level;
		data.message = format;

		va_copy(data.args, args);
		//
		loggers->invoke_function(loggers, vlog_cb, &data);
		va_end(data.args);
	}

	this->log_lock->unlock(this->log_lock);
}
METHOD(bus_t, log_, void,
	private_bus_t *this, debug_t group, level_t level, char* format, ...)
{
	va_list args;

	va_start(args, format);
	//log 间接调用vlog
	vlog(this, group, level, format, args);
	va_end(args);
}

//1注册: 通过add_logger
METHOD(bus_t, add_logger, void,
	private_bus_t *this, logger_t *logger)
{
	log_entry_t *entry;
	debug_t group;

	INIT(entry,
		.logger = logger,
	);

	this->log_lock->write_lock(this->log_lock);
	//从所有日志组中取消注册记录器（销毁 log_entry_t）
	unregister_logger(this, logger);
	//一个logger遍历向所有非静默的的日志组成员注册；add_logger多次则对于一个日志组成员会有多个不同的logger。多对多关系。
	//日志组成员见enum debug_t；logger有系统日志sys_logger、文件或终端日志file_logger和自定义日志custom_logger三种。
	//这三种各自有赋予的优先级。
	for (group = 0; group < DBG_MAX; group++)
	{
		entry->levels[group] = logger->get_level(logger, group);
		if (entry->levels[group] > LEVEL_SILENT)
		{
			//根据请求的级别在给定的日志组上注册一个 Logger，按logger的日志级别属性降序排列。level越大排在前。
			//level（见enum level_t）越大输出内容越多，优先级越高。
			register_logger(this, group, entry);
		}
	}
	this->loggers[DBG_MAX]->insert_last(this->loggers[DBG_MAX], entry);
	this->log_lock->unlock(this->log_lock);
}

/**
 * Debug levels used to control output verbosity.
 */
enum level_t {
	/** absolutely silent */
	LEVEL_SILENT = -1,
	/** most important auditing logs */
	LEVEL_AUDIT =   0,
	/** control flow */
	LEVEL_CTRL =    1,
	/** diagnose problems */
	LEVEL_DIAG =    2,
	/** raw binary blobs */
	LEVEL_RAW =     3,
	/** including sensitive data (private keys) */
	LEVEL_PRIVATE = 4,
};
//2执行：invoke_function是关键
/**
 * 对所有this包含的对象调用函数function。
 *
 * @param function	function to call for each object
 * @param ...		user data to supply to called function
 */
void (*invoke_function)(linked_list_t *this, linked_list_invoke_t function,...);

METHOD(linked_list_t, invoke_function, void,
	private_linked_list_t *this, linked_list_invoke_t fn, ...)
{
	element_t *current = this->first;
	va_list args;

	//遍历可能的系统日志sys_logger、文件或终端日志file_logger和自定义日志custom_logger  (current->value)
	//执行回调fn
	while (current)
	{
		va_start(args, fn);
		fn(current->value, args);
		va_end(args);
		current = current->next;
	}
}

回调函数为：
CALLBACK(vlog_cb, void,
	log_entry_t *entry, va_list args)
{
	log_data_t *data;

	VA_ARGS_VGET(args, data);
	//调用entry->logger->vlog方法，数据为变参args，日志级别要大于数据的级别
	if (entry->logger->vlog && entry->levels[data->group] >= data->level)
	{
		va_list copy;

		va_copy(copy, data->args);
		entry->logger->vlog(entry->logger, data->group, data->level,
							data->thread, data->ike_sa, data->message, copy);
		va_end(copy);
	}
}

CALLBACK(log_cb, void,
	log_entry_t *entry, va_list args)
{
	log_data_t *data;

	VA_ARGS_VGET(args, data);
	if (entry->logger->log && entry->levels[data->group] >= data->level)
	{
		entry->logger->log(entry->logger, data->group, data->level,
						   data->thread, data->ike_sa, data->message);
	}
}