printk 续行问题

最近在代码工程升级kernel版本后发现 代码中使用for循环dump 一些值的时候printk（“0x%x  ”,temp_data）不能续行打印，导致每个没有换行\n结束的printk在打印时自动换行。

查看后发现kernel4.9之后printk续行打印需要强制加上KERN_CONT flag. 参考 printk() and KERN_CONT [LWN.net] 有详细介绍。

加完KERN_CONT后 续行问题是解决了，但是发现了一些奇怪的现象。

example1:
printk("txt1 "); //can be also printk(KERN_CONT "txt1 ");
printk(KERN_CONT "txt2 ");
printk(KERN_CONT "txt3");
printk("\n");

输出为：
line1: txt1 txt2 txt3
line2:
line3:

example2:
​​​​​​​printk("txt1 "); //can be also ​​​​​​​printk(KERN_CONT "txt1 ");
printk(KERN_CONT "txt2 ");
printk(KERN_CONT "txt3\n");
printk("\n");

输出为：
line1:txt1 txt2 txt3
line2:
line3:

example3:
​​​​​​​printk("txt1 "); //can be also ​​​​​​​printk(KERN_CONT "txt1 ");
printk(KERN_CONT "txt2 ");
printk(KERN_CONT "txt3\n");
printk(KERN_CONT "\n");

输出为：
line1:txt1 txt2 txt3
line2:

example4:
printk("txt1");
printk("txt2");
printk(KERN_CONT "\n");

输出为：
line1:txt1
line2:txt2
line3:

根据printk() and KERN_CONT [LWN.net] 中对printk的描述， 似乎KERN_CONT仅仅作用在没有换行结尾的打印中，\n结尾的字符串使用KERN_CONT和不使用KERN_CONT应该效果相同。

 Another difference from printf() is in how a format string without a newline is treated, which is what has changed. The KERN_CONT "log level" is meant to indicate a continuation line; a printk() that lacks that flag is supposed to start a new line in the log—though that hasn't always been enforced.

当时example1 中打印 txt1 txt2 txt3后使用printk(“\n”) 居然发生两次换行。example 2也是两次换行，这看似正常。example3 只有一次换行（似乎后面一次换行没起作用）， example4只有一次换行（打印txt2 对于kernel 5.4的行为不使用KERN_CONT本来就会自动换行，后面再一次printk "\n"换行似乎没起作用）。看起来在使用KERN_CONT后对只有“\n”的字符串的处理有些特殊。

于是找到源代码：

static void cont_flush(void)
{
	if (cont.len == 0)
		return;

	log_store(cont.caller_id, cont.facility, cont.level, cont.flags,
		  cont.ts_nsec, NULL, 0, cont.buf, cont.len);
	cont.len = 0;
}

static bool cont_add(u32 caller_id, int facility, int level,
		     enum log_flags flags, const char *text, size_t len)
{
	/* If the line gets too long, split it up in separate records. */
	if (cont.len + len > sizeof(cont.buf)) {
		cont_flush();
		return false;
	}

	if (!cont.len) {
		cont.facility = facility;
		cont.level = level;
		cont.caller_id = caller_id;
		cont.ts_nsec = local_clock();
		cont.flags = flags;
	}

	memcpy(cont.buf + cont.len, text, len);
	cont.len += len;

	// The original flags come from the first line,
	// but later continuations can add a newline.
	if (flags & LOG_NEWLINE) {
		cont.flags |= LOG_NEWLINE;
		cont_flush();
	}

	return true;
}

static size_t log_output(int facility, int level, enum log_flags lflags, const char *dict, size_t dictlen, char *text, size_t text_len)
{
	const u32 caller_id = printk_caller_id();

	/*
	 * If an earlier line was buffered, and we're a continuation
	 * write from the same context, try to add it to the buffer.
	 */
	if (cont.len) {
		if (cont.caller_id == caller_id && (lflags & LOG_CONT)) {
			if (cont_add(caller_id, facility, level, lflags, text, text_len))
				return text_len;
		}
		/* Otherwise, make sure it's flushed */
		cont_flush();
	}

	/* Skip empty continuation lines that couldn't be added - they just flush */
	if (!text_len && (lflags & LOG_CONT))
		return 0;

	/* If it doesn't end in a newline, try to buffer the current line */
	if (!(lflags & LOG_NEWLINE)) {
		if (cont_add(caller_id, facility, level, lflags, text, text_len))
			return text_len;
	}

	/* Store it in the record log */
	return log_store(caller_id, facility, level, lflags, 0,
			 dict, dictlen, text, text_len);
}

/* Must be called under logbuf_lock. */
int vprintk_store(int facility, int level,
		  const char *dict, size_t dictlen,
		  const char *fmt, va_list args)
{
	static char textbuf[LOG_LINE_MAX];
	char *text = textbuf;
	size_t text_len;
	enum log_flags lflags = 0;

	/*
	 * The printf needs to come first; we need the syslog
	 * prefix which might be passed-in as a parameter.
	 */
	text_len = vscnprintf(text, sizeof(textbuf), fmt, args);

	/* mark and strip a trailing newline */
	if (text_len && text[text_len-1] == '\n') {
		text_len--;
		lflags |= LOG_NEWLINE;
	}

	/* strip kernel syslog prefix and extract log level or control flags */
	if (facility == 0) {
		int kern_level;

		while ((kern_level = printk_get_level(text)) != 0) {
			switch (kern_level) {
			case '0' ... '7':
				if (level == LOGLEVEL_DEFAULT)
					level = kern_level - '0';
				break;
			case 'c':	/* KERN_CONT */
				lflags |= LOG_CONT;
			}

			text_len -= 2;
			text += 2;
		}
	}

	if (level == LOGLEVEL_DEFAULT)
		level = default_message_loglevel;

	if (dict)
		lflags |= LOG_NEWLINE;

	return log_output(facility, level, lflags,
			  dict, dictlen, text, text_len);
}

上述只粘贴部分代码 调用流程为 vprintk_store --> log_output.重点逻辑在log_output函数，对应example 第一次printk不带换行会走到log_out中判断字符串没有换行调用cont_add先保存起来， 第二次printk 字符串使用KERN_CONT 走到log_out中判断cont.len不为0，且LOG_CONT flag置位， 继续cont_add. cont_add 缓存到txt3后，这时调用printk(“\n”) 进入后cont.len仍然不为0，但是没有LOG_CONT flag，此时会cont_flush 将之前的flush输出（输出会换行）。cont_fush后函数并没有return，继续往下调用log_store再将“\n”输出，故发生两次换行。

example2 中printk(KERN_CONT "txt3\n"), 调用cont_add 缓存"txt3\n" 在cont_add中检测到换行会cont_flush。此后printk("\n")和example1结构一致。

example3中printk(KERN_CONT "txt3\n"), 调用cont_add 缓存"txt3\n" 在cont_add中检测到换行会cont_flush。此后调用printk(KERN_CONT "\n")进入log_out，此时cont.len = 0，检测到text_len 等于0， 直接return，因此并没有发生实际的任何打印。

/* mark and strip a trailing newline */
    if (text_len && text[text_len-1] == '\n') {
        text_len--;
        lflags |= LOG_NEWLINE;
    }

example4

printk txt1时会cont_add 缓存，打印txt2时 cont.len 不为0， 且没有LOG_CONT flag，会cont_flush 将前一次的缓存（txt1）flush输出(输出会换行），然后继续往下发现“txt2”仍然不带换行flag， 调用cont_add继续缓存，最后printk(KERN_CONT "\n"), cont.len不为0且带LOG_CONT 调用cont_add加入缓存， cont_add函数中发现add的字符串以换行结尾，调用cont_flush输出。