From c098df844d7ba9b5e88ef598c74da3a9efa04012 Mon Sep 17 00:00:00 2001 From: Bo He Date: Wed, 1 May 2024 22:38:17 +0800 Subject: [PATCH 1/6] printk: enable print the cpu in the printk Signed-off-by: Bo He --- kernel/printk/printk.c | 11 +++++++---- kernel/printk/printk_ringbuffer.h | 1 + 2 files changed, 8 insertions(+), 4 deletions(-) diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 09b0841fce043..4636d8b545a12 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -957,6 +957,7 @@ void log_buf_vmcoreinfo_setup(void) VMCOREINFO_OFFSET(printk_info, ts_nsec); VMCOREINFO_OFFSET(printk_info, text_len); VMCOREINFO_OFFSET(printk_info, caller_id); + VMCOREINFO_OFFSET(printk_info, print_cpu); VMCOREINFO_OFFSET(printk_info, dev_info); VMCOREINFO_STRUCT_SIZE(dev_printk_info); @@ -1068,6 +1069,7 @@ static unsigned int __init add_to_rb(struct printk_ringbuffer *rb, dest_r.info->flags = r->info->flags; dest_r.info->ts_nsec = r->info->ts_nsec; dest_r.info->caller_id = r->info->caller_id; + dest_r.info->print_cpu = r->info->print_cpu; memcpy(&dest_r.info->dev_info, &r->info->dev_info, sizeof(dest_r.info->dev_info)); prb_final_commit(&e); @@ -1276,12 +1278,12 @@ static size_t print_syslog(unsigned int level, char *buf) return sprintf(buf, "<%u>", level); } -static size_t print_time(u64 ts, char *buf) +static size_t print_time(u64 ts, u8 print_cpu, char *buf) { unsigned long rem_nsec = do_div(ts, 1000000000); - return sprintf(buf, "[%5lu.%06lu]", - (unsigned long)ts, rem_nsec / 1000); + return sprintf(buf, "[%5lu.%06lu, %d]", + (unsigned long)ts, rem_nsec / 1000, print_cpu); } #ifdef CONFIG_PRINTK_CALLER @@ -1309,7 +1311,7 @@ static size_t info_print_prefix(const struct printk_info *info, bool syslog, len = print_syslog((info->facility << 3) | info->level, buf); if (time) - len += print_time(info->ts_nsec, buf + len); + len += print_time(info->ts_nsec, info->print_cpu, buf + len); len += print_caller(info->caller_id, buf + len); @@ -2234,6 +2236,7 @@ int vprintk_store(int facility, int level, r.info->flags = flags & 0x1f; r.info->ts_nsec = ts_nsec; r.info->caller_id = caller_id; + r.info->print_cpu = raw_smp_processor_id();; if (dev_info) memcpy(&r.info->dev_info, dev_info, sizeof(r.info->dev_info)); diff --git a/kernel/printk/printk_ringbuffer.h b/kernel/printk/printk_ringbuffer.h index 18cd25e489b89..f74a677f0aed8 100644 --- a/kernel/printk/printk_ringbuffer.h +++ b/kernel/printk/printk_ringbuffer.h @@ -20,6 +20,7 @@ struct printk_info { u8 flags:5; /* internal record flags */ u8 level:3; /* syslog level */ u32 caller_id; /* thread id or processor id */ + u32 print_cpu; struct dev_printk_info dev_info; }; From 9e5b08c155b2712e22d766924c9d7446d4fcce56 Mon Sep 17 00:00:00 2001 From: Bo He Date: Wed, 1 May 2024 15:16:24 +0800 Subject: [PATCH 2/6] printk: add ignore loglevel mechanism for specific consoles Pstore console follows global loglevel kernel parameter which is most of time set to a reasonable value, 5 as example, in order to keep real HW consoles with a low activity. This is an issue on production systems where the pstore console (console-ramoops file) is used in post-mortem debug as it misses all lower level messages and makes analysis harder. Kernel does not support the ability to ignore log level for a set of consoles. It supports only overall setting named ignore_level that affects all the consoles. This patch provides a fine tuning of the log level management per consoles by introducing CON_IGNORELEVEL flag. Apply this flag to pstore console allows to have full kernel messages on pstore console while still having a lower level on others. It ease debugging to always have full log level on pstore console, even on production devices where minimum debugging features are available. Signed-off-by: Bo He --- fs/pstore/platform.c | 2 +- include/linux/console.h | 1 + kernel/printk/printk.c | 13 ++++++++++--- 3 files changed, 12 insertions(+), 4 deletions(-) diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c index ad96ba97d8f97..83aec192997a2 100644 --- a/fs/pstore/platform.c +++ b/fs/pstore/platform.c @@ -516,7 +516,7 @@ static void pstore_register_console(void) * Always initialize flags here since prior unregister_console() * calls may have changed settings (specifically CON_ENABLED). */ - pstore_console.flags = CON_PRINTBUFFER | CON_ENABLED | CON_ANYTIME; + pstore_console.flags = CON_PRINTBUFFER | CON_ENABLED | CON_ANYTIME | CON_IGNORELEVEL; register_console(&pstore_console); } diff --git a/include/linux/console.h b/include/linux/console.h index 7cd758a4f44ed..79bf25340f867 100644 --- a/include/linux/console.h +++ b/include/linux/console.h @@ -136,6 +136,7 @@ static inline int con_debug_leave(void) #define CON_ANYTIME (16) /* Safe to call when cpu is offline */ #define CON_BRL (32) /* Used for a braille device */ #define CON_EXTENDED (64) /* Use the extended output format a la /dev/kmsg */ +#define CON_IGNORELEVEL (128) /* Used to ignore log level for a console */ struct console { char name[16]; diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 4636d8b545a12..83fd99a1501a6 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -1212,7 +1212,11 @@ MODULE_PARM_DESC(ignore_loglevel, static bool suppress_message_printing(int level) { +#ifndef CON_IGNORELEVEL return (level >= console_loglevel && !ignore_loglevel); +#else + return false; +#endif } #ifdef CONFIG_BOOT_PRINTK_DELAY @@ -1930,7 +1934,7 @@ static int console_trylock_spinning(void) * log_buf[start] to log_buf[end - 1]. * The console_lock must be held. */ -static void call_console_drivers(const char *ext_text, size_t ext_len, +static void call_console_drivers(int level, const char *ext_text, size_t ext_len, const char *text, size_t len) { static char dropped_text[64]; @@ -1959,6 +1963,9 @@ static void call_console_drivers(const char *ext_text, size_t ext_len, if (!cpu_online(smp_processor_id()) && !(con->flags & CON_ANYTIME)) continue; + if (level >= console_loglevel && + !(con->flags & CON_IGNORELEVEL) && !ignore_loglevel) + continue; if (con->flags & CON_EXTENDED) con->write(con, ext_text, ext_len); else { @@ -2348,7 +2355,7 @@ static ssize_t msg_print_ext_body(char *buf, size_t size, struct dev_printk_info *dev_info) { return 0; } static void console_lock_spinning_enable(void) { } static int console_lock_spinning_disable_and_check(void) { return 0; } -static void call_console_drivers(const char *ext_text, size_t ext_len, +static void call_console_drivers(int level, const char *ext_text, size_t ext_len, const char *text, size_t len) {} static bool suppress_message_printing(int level) { return false; } @@ -2764,7 +2771,7 @@ void console_unlock(void) console_lock_spinning_enable(); stop_critical_timings(); /* don't trace print latency */ - call_console_drivers(ext_text, ext_len, text, len); + call_console_drivers(r.info->level, ext_text, ext_len, text, len); start_critical_timings(); handover = console_lock_spinning_disable_and_check(); From edcdd337a6d53f95604bcdc35fa001b06059a9de Mon Sep 17 00:00:00 2001 From: Bo He Date: Wed, 1 May 2024 19:59:56 +0800 Subject: [PATCH 3/6] printk: Add console fast attribute to support pstore dump 1. Add a new console flag CON_FAST in order to be able to disable slow consoles in cases where a considerable amount of data should be logged in a limited amount of time (eg. show_state in a WD warning interrupt) 2. Mark pstore console as CON_FAST Signed-off-by: Bo He --- fs/pstore/platform.c | 2 +- include/linux/console.h | 4 ++++ kernel/printk/printk.c | 36 ++++++++++++++++++++++++++++++++++++ 3 files changed, 41 insertions(+), 1 deletion(-) diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c index 83aec192997a2..926ca1ff0e54d 100644 --- a/fs/pstore/platform.c +++ b/fs/pstore/platform.c @@ -516,7 +516,7 @@ static void pstore_register_console(void) * Always initialize flags here since prior unregister_console() * calls may have changed settings (specifically CON_ENABLED). */ - pstore_console.flags = CON_PRINTBUFFER | CON_ENABLED | CON_ANYTIME | CON_IGNORELEVEL; + pstore_console.flags = CON_PRINTBUFFER | CON_ENABLED | CON_ANYTIME | CON_IGNORELEVEL | CON_FAST; register_console(&pstore_console); } diff --git a/include/linux/console.h b/include/linux/console.h index 79bf25340f867..9033fbeb2d8c4 100644 --- a/include/linux/console.h +++ b/include/linux/console.h @@ -137,6 +137,7 @@ static inline int con_debug_leave(void) #define CON_BRL (32) /* Used for a braille device */ #define CON_EXTENDED (64) /* Use the extended output format a la /dev/kmsg */ #define CON_IGNORELEVEL (128) /* Used to ignore log level for a console */ +#define CON_FAST (256) /* This is a fast console */ struct console { char name[16]; @@ -226,4 +227,7 @@ extern void console_init(void); void dummycon_register_output_notifier(struct notifier_block *nb); void dummycon_unregister_output_notifier(struct notifier_block *nb); +void console_suspend_slow(void); +void console_restore_slow(void); + #endif /* _LINUX_CONSOLE_H */ diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 83fd99a1501a6..5434d063c5903 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -479,6 +479,11 @@ u32 log_buf_len_get(void) } EXPORT_SYMBOL_GPL(log_buf_len_get); +/* Give the posibility to temporary disable slow (!CON_FAST) consoles */ +static atomic_t console_slow_suspended = ATOMIC_INIT(0); +/* Keep the number of slow suspend in check */ +#define MAX_SLOW_SUSPEND_COUNT (50) + /* * Define how much of the log buffer we could take at maximum. The value * must be greater than two. Note that only half of the buffer is available @@ -1956,6 +1961,9 @@ static void call_console_drivers(int level, const char *ext_text, size_t ext_len for_each_console(con) { if (exclusive_console && con != exclusive_console) continue; + if (atomic_read(&console_slow_suspended) && + !(con->flags & CON_FAST)) + continue; if (!(con->flags & CON_ENABLED)) continue; if (!con->write) @@ -2862,6 +2870,34 @@ void console_flush_on_panic(enum con_flush_mode mode) console_unlock(); } +void console_suspend_slow(void) +{ + struct console *c; + + if (atomic_read(&console_slow_suspended) >= MAX_SLOW_SUSPEND_COUNT) { + pr_debug("Max slow suspend\n"); + return; + } + if (atomic_add_return(1, &console_slow_suspended) == 1) { + pr_err("Suspend slow consoles\n"); + for_each_console(c) + if (!(c->flags & CON_FAST)) + pr_debug("%s suspended\n", c->name); + } +} +EXPORT_SYMBOL(console_suspend_slow); + +void console_restore_slow(void) +{ + if (atomic_read(&console_slow_suspended) <= 0) { + pr_debug("Min slow suspend\n"); + return; + } + + if (!atomic_sub_return(1, &console_slow_suspended)) + pr_err("Restore slow consoles\n"); +} +EXPORT_SYMBOL(console_restore_slow); /* * Return the console tty driver structure and its associated index */ From 262e0f4513f0ecc4dfbc47fef86565742b75c880 Mon Sep 17 00:00:00 2001 From: Bo He Date: Wed, 1 May 2024 20:05:59 +0800 Subject: [PATCH 4/6] intel_tasks_dumper: Init Add a new panic handler that will be able to dump a full tasks state upon various panics. Because this dump could be time sensitive, also temporary disable the slow consoles during this. By default only soft/hard lockups and Kernel watchdog warning interrupts are targeted, but the functionality can be extended to all panics or forced disable by "force_en" and "force_dis" module parameters. Signed-off-by: Bo He --- drivers/platform/x86/Kconfig | 6 ++ drivers/platform/x86/Makefile | 1 + drivers/platform/x86/intel-tasks-dumper.c | 104 ++++++++++++++++++++++ 3 files changed, 111 insertions(+) create mode 100644 drivers/platform/x86/intel-tasks-dumper.c diff --git a/drivers/platform/x86/Kconfig b/drivers/platform/x86/Kconfig index bb69d1dab64b1..1f0d6129fe003 100644 --- a/drivers/platform/x86/Kconfig +++ b/drivers/platform/x86/Kconfig @@ -1027,6 +1027,12 @@ config INTEL_SCU_IPC_UTIL low level access for debug work and updating the firmware. Say N unless you will be doing this on an Intel MID platform. +config INTEL_TASKS_DUMP + bool "Intel panic tasks dumper" + depends on PRINTK + help + This provides a way to get full tasks dump in case of panic. + endif # X86_PLATFORM_DEVICES config PMC_ATOM diff --git a/drivers/platform/x86/Makefile b/drivers/platform/x86/Makefile index 411d07cd05a7b..59c7b053311db 100644 --- a/drivers/platform/x86/Makefile +++ b/drivers/platform/x86/Makefile @@ -107,6 +107,7 @@ obj-$(CONFIG_I2C_MULTI_INSTANTIATE) += i2c-multi-instantiate.o obj-$(CONFIG_MLX_PLATFORM) += mlx-platform.o obj-$(CONFIG_TOUCHSCREEN_DMI) += touchscreen_dmi.o obj-$(CONFIG_WIRELESS_HOTKEY) += wireless-hotkey.o +obj-$(CONFIG_INTEL_TASKS_DUMP) += intel-tasks-dumper.o # Intel uncore drivers obj-$(CONFIG_INTEL_IPS) += intel_ips.o diff --git a/drivers/platform/x86/intel-tasks-dumper.c b/drivers/platform/x86/intel-tasks-dumper.c new file mode 100644 index 0000000000000..627f28feb1996 --- /dev/null +++ b/drivers/platform/x86/intel-tasks-dumper.c @@ -0,0 +1,104 @@ +/* + * Intel Trace Hub to USB dvc-trace driver + * + * Copyright (C) 2015, Intel Corporation. + * + * This software is licensed under the terms of the GNU General Public + * License version 2, as published by the Free Software Foundation, and + * may be copied, distributed, and modified under those terms. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + */ + +#define pr_fmt(fmt) KBUILD_MODNAME ": %s: " fmt, __func__ + +#include +#include +#include +#include +#include + +static const char * const filter[] = { + "hung_task:", /* hung task */ + "Watchdog detected", /* Hard lockup */ + "softlockup:", /* Soft lockup */ + "Kernel Watchdog", /* iTCO warning */ +}; + +static int force_en; +module_param(force_en, int, S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP); +MODULE_PARM_DESC(force_en, "Force enable"); + +static int force_dis; +module_param(force_dis, int, S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP); +MODULE_PARM_DESC(force_dis, "Force disable"); + +/* 1 pass, 0 not*/ +static int check_filter(const char *v) +{ + int i; + + if (force_dis) + return 0; + + if (force_en) + return 1; + + for (i = 0; i < (sizeof(filter) / sizeof(*filter)); i++) { + if (!strncmp(v, filter[i], strlen(filter[i]))) { + pr_debug("Matching filter[%d] %s", i, filter[i]); + return 1; + } + } + return 0; +} + +static int intel_task_panic_hndl(struct notifier_block *n, + unsigned long val, void *v) +{ + char *buf = v; + + /* for panic val is hardcoded to 0 */ + if (val) { + return NOTIFY_OK; + } else if (!check_filter(buf)) { + pr_info("Skip tasks dumper.\n"); + return NOTIFY_OK; + } + + console_suspend_slow(); + pr_info(" --- tasks dumper [BEGIN] ---\n"); + show_state_filter(0); + pr_info(" --- tasks dumper [END] ---\n"); + console_restore_slow(); + + /* maybe NOTIFY_STOP_MASK ....*/ + return NOTIFY_OK; +} + +static struct notifier_block panic_notifier = { + .notifier_call = intel_task_panic_hndl, + .priority = 2, /*Not the last one*/ +}; + +static int __init intel_tasks_dumper_init(void) +{ + pr_info("Register tasks dumper\n"); + atomic_notifier_chain_register(&panic_notifier_list, &panic_notifier); + return 0; +} + +static void __exit intel_tasks_dumper_exit(void) +{ + atomic_notifier_chain_unregister(&panic_notifier_list, &panic_notifier); +} + +module_init(intel_tasks_dumper_init); +module_exit(intel_tasks_dumper_exit); + +MODULE_LICENSE("GPL v2"); +MODULE_AUTHOR("Traian Schiau "); From 747be832a24e07017c6c9f2186de4437a45368fc Mon Sep 17 00:00:00 2001 From: Bo He Date: Wed, 1 May 2024 21:45:03 +0800 Subject: [PATCH 5/6] enable all_cpu_backtrace for both soft and hard lock Signed-off-by: Bo He --- kernel/watchdog.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/kernel/watchdog.c b/kernel/watchdog.c index 2b1c9d202f924..f839d4474bcfb 100644 --- a/kernel/watchdog.c +++ b/kernel/watchdog.c @@ -52,7 +52,7 @@ unsigned long *watchdog_cpumask_bits = cpumask_bits(&watchdog_cpumask); #ifdef CONFIG_HARDLOCKUP_DETECTOR # ifdef CONFIG_SMP -int __read_mostly sysctl_hardlockup_all_cpu_backtrace; +int __read_mostly sysctl_hardlockup_all_cpu_backtrace = 1; # endif /* CONFIG_SMP */ /* @@ -163,7 +163,7 @@ static void lockup_detector_update_enable(void) #define SOFTLOCKUP_DELAY_REPORT ULONG_MAX #ifdef CONFIG_SMP -int __read_mostly sysctl_softlockup_all_cpu_backtrace; +int __read_mostly sysctl_softlockup_all_cpu_backtrace = 1; #endif static struct cpumask watchdog_allowed_mask __read_mostly; From e4cb5d16d8f6d38ab415ad8aa890367ebcf018c9 Mon Sep 17 00:00:00 2001 From: Bo He Date: Wed, 1 May 2024 21:57:59 +0800 Subject: [PATCH 6/6] reboot: add a timer to moniter if reboot/shutdown hangs Signed-off-by: Bo He --- kernel/reboot.c | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/kernel/reboot.c b/kernel/reboot.c index 957ef52b8af44..944fde87cf3d5 100644 --- a/kernel/reboot.c +++ b/kernel/reboot.c @@ -71,8 +71,17 @@ void emergency_restart(void) } EXPORT_SYMBOL_GPL(emergency_restart); +#define REBOOT_WORK_TIMEOUT 60 +static void reboot_timeout_fn(struct timer_list *unused) +{ + pr_err("reboot/shutdown timeout!\n"); + BUG(); +} +static DEFINE_TIMER(reboot_timer, reboot_timeout_fn); + void kernel_restart_prepare(char *cmd) { + mod_timer(&reboot_timer, jiffies + REBOOT_WORK_TIMEOUT * HZ); blocking_notifier_call_chain(&reboot_notifier_list, SYS_RESTART, cmd); system_state = SYSTEM_RESTART; usermodehelper_disable(); @@ -260,6 +269,7 @@ EXPORT_SYMBOL_GPL(kernel_restart); static void kernel_shutdown_prepare(enum system_states state) { + mod_timer(&reboot_timer, jiffies + REBOOT_WORK_TIMEOUT * HZ); blocking_notifier_call_chain(&reboot_notifier_list, (state == SYSTEM_HALT) ? SYS_HALT : SYS_POWER_OFF, NULL); system_state = state;