diff options
| -rw-r--r-- | Documentation/core-api/printk-formats.rst | 5 | ||||
| -rw-r--r-- | kernel/printk/printk.c | 86 | ||||
| -rw-r--r-- | lib/vsprintf.c | 216 |
3 files changed, 158 insertions, 149 deletions
diff --git a/Documentation/core-api/printk-formats.rst b/Documentation/core-api/printk-formats.rst index 86023c33906f..ff48b55040ef 100644 --- a/Documentation/core-api/printk-formats.rst +++ b/Documentation/core-api/printk-formats.rst @@ -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. diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 9bf5404397e0..b77150ad1965 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -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,7 +1924,8 @@ asmlinkage int vprintk_emit(int facility, int level, preempt_enable(); } - wake_up_klogd(); + if (pending_output) + wake_up_klogd(); return printed_len; } EXPORT_SYMBOL(vprintk_emit); @@ -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 @@ again: 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 @@ skip: 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 @@ skip: 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(); diff --git a/lib/vsprintf.c b/lib/vsprintf.c index 376de10929b3..ad4fbe5bc730 100644 --- a/lib/vsprintf.c +++ b/lib/vsprintf.c @@ -613,6 +613,109 @@ char *string(char *buf, char *end, const char *s, struct printf_spec 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(¬_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(¬_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(¬_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(¬_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(¬_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(¬_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': |