Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit a67eefad authored by Linus Torvalds's avatar Linus Torvalds
Browse files

Merge tag 'printk-for-4.20' of git://git.kernel.org/pub/scm/linux/kernel/git/pmladek/printk 

Pull printk updates from Petr Mladek:

 - Fix two more locations where printf formatting leaked pointers

 - Better log_buf_len parameter handling

 - Add prefix to messages from printk code

 - Do not miss messages on other consoles when the log is replayed on a
   new one

 - Reduce race between console registration and panic() when the log
   might get replayed on all consoles

 - Some cont buffer code clean up

 - Call console only when there is something to do (log vs cont buffer)

* tag 'printk-for-4.20' of git://git.kernel.org/pub/scm/linux/kernel/git/pmladek/printk:
  lib/vsprintf: Hash printed address for netdev bits fallback
  lib/vsprintf: Hash legacy clock addresses
  lib/vsprintf: Prepare for more general use of ptr_to_id()
  lib/vsprintf: Make ptr argument conts in ptr_to_id()
  printk: fix integer overflow in setup_log_buf()
  printk: do not preliminary split up cont buffer
  printk: lock/unlock console only for new logbuf entries
  printk: keep kernel cont support always enabled
  printk: Give error on attempt to set log buffer length to over 2G
  printk: Add KBUILD_MODNAME and remove a redundant print prefix
  printk: Correct wrong casting
  printk: Fix panic caused by passing log_buf_len to command line
  printk: CON_PRINTBUFFER console registration is a bit racy
  printk: Do not miss new messages when replaying the log
parents 62606c22 54edeb03

Documentation/core-api/printk-formats.rst

+2 −3
Original line number Diff line number Diff line
@@ -420,9 +420,8 @@ struct clk 
	%pC	pll1

	%pCn	pll1



For printing struct clk structures. %pC and %pCn print the name

(Common Clock Framework) or address (legacy clock framework) of the

structure.

For printing struct clk structures. %pC and %pCn print the name of the clock

(Common Clock Framework) or a unique 32-bit ID (legacy clock framework).



Passed by reference.

kernel/printk/printk.c

+48 −38
Original line number Diff line number Diff line
@@ -16,6 +16,8 @@ 
 *	01Mar01 Andrew Morton

 */



#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt



#include <linux/kernel.h>

#include <linux/mm.h>

#include <linux/tty.h>
@@ -192,16 +194,7 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write, 
	return 0;

}



/*

 * Number of registered extended console drivers.

 *

 * If extended consoles are present, in-kernel cont reassembly is disabled

 * and each fragment is stored as a separate log entry with proper

 * continuation flag so that every emitted message has full metadata.  This

 * doesn't change the result for regular consoles or /proc/kmsg.  For

 * /dev/kmsg, as long as the reader concatenates messages according to

 * consecutive continuation flags, the end result should be the same too.

 */

/* Number of registered extended console drivers. */

static int nr_ext_console_drivers;



/*
@@ -423,6 +416,7 @@ static u32 log_next_idx; 
/* the next printk record to write to the console */

static u64 console_seq;

static u32 console_idx;

static u64 exclusive_console_stop_seq;



/* the next printk record to read after the last 'clear' command */

static u64 clear_seq;
@@ -437,6 +431,7 @@ static u32 clear_idx; 
/* record buffer */

#define LOG_ALIGN __alignof__(struct printk_log)

#define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)

#define LOG_BUF_LEN_MAX (u32)(1 << 31)

static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);

static char *log_buf = __log_buf;

static u32 log_buf_len = __LOG_BUF_LEN;
@@ -1037,18 +1032,28 @@ void log_buf_vmcoreinfo_setup(void) 
static unsigned long __initdata new_log_buf_len;



/* we practice scaling the ring buffer by powers of 2 */

static void __init log_buf_len_update(unsigned size)

static void __init log_buf_len_update(u64 size)

{

	if (size > (u64)LOG_BUF_LEN_MAX) {

		size = (u64)LOG_BUF_LEN_MAX;

		pr_err("log_buf over 2G is not supported.\n");

	}



	if (size)

		size = roundup_pow_of_two(size);

	if (size > log_buf_len)

		new_log_buf_len = size;

		new_log_buf_len = (unsigned long)size;

}



/* save requested log_buf_len since it's too early to process it */

static int __init log_buf_len_setup(char *str)

{

	unsigned size = memparse(str, &str);

	u64 size;



	if (!str)

		return -EINVAL;



	size = memparse(str, &str);



	log_buf_len_update(size);
@@ -1093,7 +1098,7 @@ void __init setup_log_buf(int early) 
{

	unsigned long flags;

	char *new_log_buf;

	int free;

	unsigned int free;



	if (log_buf != __log_buf)

		return;
@@ -1113,7 +1118,7 @@ void __init setup_log_buf(int early) 
	}



	if (unlikely(!new_log_buf)) {

		pr_err("log_buf_len: %ld bytes not available\n",

		pr_err("log_buf_len: %lu bytes not available\n",

			new_log_buf_len);

		return;

	}
@@ -1126,8 +1131,8 @@ void __init setup_log_buf(int early) 
	memcpy(log_buf, __log_buf, __LOG_BUF_LEN);

	logbuf_unlock_irqrestore(flags);



	pr_info("log_buf_len: %d bytes\n", log_buf_len);

	pr_info("early log buf free: %d(%d%%)\n",

	pr_info("log_buf_len: %u bytes\n", log_buf_len);

	pr_info("early log buf free: %u(%u%%)\n",

		free, (free * 100) / __LOG_BUF_LEN);

}
@@ -1767,12 +1772,8 @@ static void cont_flush(void) 


static bool cont_add(int facility, int level, enum log_flags flags, const char *text, size_t len)

{

	/*

	 * If ext consoles are present, flush and skip in-kernel

	 * continuation.  See nr_ext_console_drivers definition.  Also, if

	 * the line gets too long, split it up in separate records.

	 */

	if (nr_ext_console_drivers || cont.len + len > sizeof(cont.buf)) {

	/* If the line gets too long, split it up in separate records. */

	if (cont.len + len > sizeof(cont.buf)) {

		cont_flush();

		return false;

	}
@@ -1795,9 +1796,6 @@ static bool cont_add(int facility, int level, enum log_flags flags, const char * 
		cont_flush();

	}



	if (cont.len > (sizeof(cont.buf) * 80) / 100)

		cont_flush();



	return true;

}
@@ -1889,8 +1887,9 @@ asmlinkage int vprintk_emit(int facility, int level, 
			    const char *fmt, va_list args)

{

	int printed_len;

	bool in_sched = false;

	bool in_sched = false, pending_output;

	unsigned long flags;

	u64 curr_log_seq;



	if (level == LOGLEVEL_SCHED) {

		level = LOGLEVEL_DEFAULT;
@@ -1902,11 +1901,13 @@ asmlinkage int vprintk_emit(int facility, int level, 


	/* This stops the holder of console_sem just where we want him */

	logbuf_lock_irqsave(flags);

	curr_log_seq = log_next_seq;

	printed_len = vprintk_store(facility, level, dict, dictlen, fmt, args);

	pending_output = (curr_log_seq != log_next_seq);

	logbuf_unlock_irqrestore(flags);



	/* If called from the scheduler, we can not call up(). */

	if (!in_sched) {

	if (!in_sched && pending_output) {

		/*

		 * Disable preemption to avoid being preempted while holding

		 * console_sem which would prevent anyone from printing to
@@ -1923,6 +1924,7 @@ asmlinkage int vprintk_emit(int facility, int level, 
		preempt_enable();

	}



	if (pending_output)

		wake_up_klogd();

	return printed_len;

}
@@ -2009,6 +2011,7 @@ static u64 syslog_seq; 
static u32 syslog_idx;

static u64 console_seq;

static u32 console_idx;

static u64 exclusive_console_stop_seq;

static u64 log_first_seq;

static u32 log_first_idx;

static u64 log_next_seq;
@@ -2351,8 +2354,9 @@ void console_unlock(void) 
		printk_safe_enter_irqsave(flags);

		raw_spin_lock(&logbuf_lock);

		if (console_seq < log_first_seq) {

			len = sprintf(text, "** %u printk messages dropped **\n",

				      (unsigned)(log_first_seq - console_seq));

			len = sprintf(text,

				      "** %llu printk messages dropped **\n",

				      log_first_seq - console_seq);



			/* messages are gone, move to first one */

			console_seq = log_first_seq;
@@ -2376,6 +2380,12 @@ void console_unlock(void) 
			goto skip;

		}



		/* Output to all consoles once old messages replayed. */

		if (unlikely(exclusive_console &&

			     console_seq >= exclusive_console_stop_seq)) {

			exclusive_console = NULL;

		}



		len += msg_print_text(msg,

				console_msg_format & MSG_FORMAT_SYSLOG,

				text + len,
@@ -2418,10 +2428,6 @@ void console_unlock(void) 


	console_locked = 0;



	/* Release the exclusive_console once it is used */

	if (unlikely(exclusive_console))

		exclusive_console = NULL;



	raw_spin_unlock(&logbuf_lock);



	up_console_sem();
@@ -2688,8 +2694,7 @@ void register_console(struct console *newcon) 
	}



	if (newcon->flags & CON_EXTENDED)

		if (!nr_ext_console_drivers++)

			pr_info("printk: continuation disabled due to ext consoles, expect more fragments in /dev/kmsg\n");

		nr_ext_console_drivers++;



	if (newcon->flags & CON_PRINTBUFFER) {

		/*
@@ -2699,13 +2704,18 @@ void register_console(struct console *newcon) 
		logbuf_lock_irqsave(flags);

		console_seq = syslog_seq;

		console_idx = syslog_idx;

		logbuf_unlock_irqrestore(flags);

		/*

		 * We're about to replay the log buffer.  Only do this to the

		 * just-registered console to avoid excessive message spam to

		 * the already-registered consoles.

		 *

		 * Set exclusive_console with disabled interrupts to reduce

		 * race window with eventual console_flush_on_panic() that

		 * ignores console_lock.

		 */

		exclusive_console = newcon;

		exclusive_console_stop_seq = console_seq;

		logbuf_unlock_irqrestore(flags);

	}

	console_unlock();

	console_sysfs_notify();

lib/vsprintf.c

+108 −108
Original line number Diff line number Diff line
@@ -612,6 +612,109 @@ char *string(char *buf, char *end, const char *s, struct printf_spec spec) 
	return widen_string(buf, len, end, spec);

}



static noinline_for_stack

char *pointer_string(char *buf, char *end, const void *ptr,

		     struct printf_spec spec)

{

	spec.base = 16;

	spec.flags |= SMALL;

	if (spec.field_width == -1) {

		spec.field_width = 2 * sizeof(ptr);

		spec.flags |= ZEROPAD;

	}



	return number(buf, end, (unsigned long int)ptr, spec);

}



/* Make pointers available for printing early in the boot sequence. */

static int debug_boot_weak_hash __ro_after_init;



static int __init debug_boot_weak_hash_enable(char *str)

{

	debug_boot_weak_hash = 1;

	pr_info("debug_boot_weak_hash enabled\n");

	return 0;

}

early_param("debug_boot_weak_hash", debug_boot_weak_hash_enable);



static DEFINE_STATIC_KEY_TRUE(not_filled_random_ptr_key);

static siphash_key_t ptr_key __read_mostly;



static void enable_ptr_key_workfn(struct work_struct *work)

{

	get_random_bytes(&ptr_key, sizeof(ptr_key));

	/* Needs to run from preemptible context */

	static_branch_disable(&not_filled_random_ptr_key);

}



static DECLARE_WORK(enable_ptr_key_work, enable_ptr_key_workfn);



static void fill_random_ptr_key(struct random_ready_callback *unused)

{

	/* This may be in an interrupt handler. */

	queue_work(system_unbound_wq, &enable_ptr_key_work);

}



static struct random_ready_callback random_ready = {

	.func = fill_random_ptr_key

};



static int __init initialize_ptr_random(void)

{

	int key_size = sizeof(ptr_key);

	int ret;



	/* Use hw RNG if available. */

	if (get_random_bytes_arch(&ptr_key, key_size) == key_size) {

		static_branch_disable(&not_filled_random_ptr_key);

		return 0;

	}



	ret = add_random_ready_callback(&random_ready);

	if (!ret) {

		return 0;

	} else if (ret == -EALREADY) {

		/* This is in preemptible context */

		enable_ptr_key_workfn(&enable_ptr_key_work);

		return 0;

	}



	return ret;

}

early_initcall(initialize_ptr_random);



/* Maps a pointer to a 32 bit unique identifier. */

static char *ptr_to_id(char *buf, char *end, const void *ptr,

		       struct printf_spec spec)

{

	const char *str = sizeof(ptr) == 8 ? "(____ptrval____)" : "(ptrval)";

	unsigned long hashval;



	/* When debugging early boot use non-cryptographically secure hash. */

	if (unlikely(debug_boot_weak_hash)) {

		hashval = hash_long((unsigned long)ptr, 32);

		return pointer_string(buf, end, (const void *)hashval, spec);

	}



	if (static_branch_unlikely(&not_filled_random_ptr_key)) {

		spec.field_width = 2 * sizeof(ptr);

		/* string length must be less than default_width */

		return string(buf, end, str, spec);

	}



#ifdef CONFIG_64BIT

	hashval = (unsigned long)siphash_1u64((u64)ptr, &ptr_key);

	/*

	 * Mask off the first 32 bits, this makes explicit that we have

	 * modified the address (and 32 bits is plenty for a unique ID).

	 */

	hashval = hashval & 0xffffffff;

#else

	hashval = (unsigned long)siphash_1u32((u32)ptr, &ptr_key);

#endif

	return pointer_string(buf, end, (const void *)hashval, spec);

}



static noinline_for_stack

char *dentry_name(char *buf, char *end, const struct dentry *d, struct printf_spec spec,

		  const char *fmt)
@@ -1357,20 +1460,6 @@ char *uuid_string(char *buf, char *end, const u8 *addr, 
	return string(buf, end, uuid, spec);

}



static noinline_for_stack

char *pointer_string(char *buf, char *end, const void *ptr,

		     struct printf_spec spec)

{

	spec.base = 16;

	spec.flags |= SMALL;

	if (spec.field_width == -1) {

		spec.field_width = 2 * sizeof(ptr);

		spec.flags |= ZEROPAD;

	}



	return number(buf, end, (unsigned long int)ptr, spec);

}



int kptr_restrict __read_mostly;



static noinline_for_stack
@@ -1421,7 +1510,8 @@ char *restricted_pointer(char *buf, char *end, const void *ptr, 
}



static noinline_for_stack

char *netdev_bits(char *buf, char *end, const void *addr, const char *fmt)

char *netdev_bits(char *buf, char *end, const void *addr,

		  struct printf_spec spec,  const char *fmt)

{

	unsigned long long num;

	int size;
@@ -1432,9 +1522,7 @@ char *netdev_bits(char *buf, char *end, const void *addr, const char *fmt) 
		size = sizeof(netdev_features_t);

		break;

	default:

		num = (unsigned long)addr;

		size = sizeof(unsigned long);

		break;

		return ptr_to_id(buf, end, addr, spec);

	}



	return special_hex_number(buf, end, num, size);
@@ -1474,7 +1562,7 @@ char *clock(char *buf, char *end, struct clk *clk, struct printf_spec spec, 
#ifdef CONFIG_COMMON_CLK

		return string(buf, end, __clk_get_name(clk), spec);

#else

		return special_hex_number(buf, end, (unsigned long)clk, sizeof(unsigned long));

		return ptr_to_id(buf, end, clk, spec);

#endif

	}

}
@@ -1651,94 +1739,6 @@ char *device_node_string(char *buf, char *end, struct device_node *dn, 
	return widen_string(buf, buf - buf_start, end, spec);

}



/* Make pointers available for printing early in the boot sequence. */

static int debug_boot_weak_hash __ro_after_init;



static int __init debug_boot_weak_hash_enable(char *str)

{

	debug_boot_weak_hash = 1;

	pr_info("debug_boot_weak_hash enabled\n");

	return 0;

}

early_param("debug_boot_weak_hash", debug_boot_weak_hash_enable);



static DEFINE_STATIC_KEY_TRUE(not_filled_random_ptr_key);

static siphash_key_t ptr_key __read_mostly;



static void enable_ptr_key_workfn(struct work_struct *work)

{

	get_random_bytes(&ptr_key, sizeof(ptr_key));

	/* Needs to run from preemptible context */

	static_branch_disable(&not_filled_random_ptr_key);

}



static DECLARE_WORK(enable_ptr_key_work, enable_ptr_key_workfn);



static void fill_random_ptr_key(struct random_ready_callback *unused)

{

	/* This may be in an interrupt handler. */

	queue_work(system_unbound_wq, &enable_ptr_key_work);

}



static struct random_ready_callback random_ready = {

	.func = fill_random_ptr_key

};



static int __init initialize_ptr_random(void)

{

	int key_size = sizeof(ptr_key);

	int ret;



	/* Use hw RNG if available. */

	if (get_random_bytes_arch(&ptr_key, key_size) == key_size) {

		static_branch_disable(&not_filled_random_ptr_key);

		return 0;

	}



	ret = add_random_ready_callback(&random_ready);

	if (!ret) {

		return 0;

	} else if (ret == -EALREADY) {

		/* This is in preemptible context */

		enable_ptr_key_workfn(&enable_ptr_key_work);

		return 0;

	}



	return ret;

}

early_initcall(initialize_ptr_random);



/* Maps a pointer to a 32 bit unique identifier. */

static char *ptr_to_id(char *buf, char *end, void *ptr, struct printf_spec spec)

{

	const char *str = sizeof(ptr) == 8 ? "(____ptrval____)" : "(ptrval)";

	unsigned long hashval;



	/* When debugging early boot use non-cryptographically secure hash. */

	if (unlikely(debug_boot_weak_hash)) {

		hashval = hash_long((unsigned long)ptr, 32);

		return pointer_string(buf, end, (const void *)hashval, spec);

	}



	if (static_branch_unlikely(&not_filled_random_ptr_key)) {

		spec.field_width = 2 * sizeof(ptr);

		/* string length must be less than default_width */

		return string(buf, end, str, spec);

	}



#ifdef CONFIG_64BIT

	hashval = (unsigned long)siphash_1u64((u64)ptr, &ptr_key);

	/*

	 * Mask off the first 32 bits, this makes explicit that we have

	 * modified the address (and 32 bits is plenty for a unique ID).

	 */

	hashval = hashval & 0xffffffff;

#else

	hashval = (unsigned long)siphash_1u32((u32)ptr, &ptr_key);

#endif

	return pointer_string(buf, end, (const void *)hashval, spec);

}



/*

 * Show a '%p' thing.  A kernel extension is that the '%p' is followed

 * by an extra set of alphanumeric characters that are extended format
@@ -1942,7 +1942,7 @@ char *pointer(const char *fmt, char *buf, char *end, void *ptr, 
			break;

		return restricted_pointer(buf, end, ptr, spec);

	case 'N':

		return netdev_bits(buf, end, ptr, fmt);

		return netdev_bits(buf, end, ptr, spec, fmt);

	case 'a':

		return address_val(buf, end, ptr, fmt);

	case 'd':