Skip to content

Commit 3ef4ea3

Browse files
committed
Merge tag 'printk-for-5.18' of git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux
Pull printk updates from Petr Mladek: - Make %pK behave the same as %p for kptr_restrict == 0 also with no_hash_pointers parameter - Ignore the default console in the device tree also when console=null or console="" is used on the command line - Document console=null and console="" behavior - Prevent a deadlock and a livelock caused by console_lock in panic() - Make console_lock available for panicking CPU - Fast query for the next to-be-used sequence number - Use the expected return values in printk.devkmsg __setup handler - Use the correct atomic operations in wake_up_klogd() irq_work handler - Avoid possible unaligned access when handling %4cc printing format * tag 'printk-for-5.18' of git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux: printk: fix return value of printk.devkmsg __setup handler vsprintf: Fix %pK with kptr_restrict == 0 printk: make suppress_panic_printk static printk: Set console_set_on_cmdline=1 when __add_preferred_console() is called with user_specified == true Docs: printk: add 'console=null|""' to admin/kernel-parameters printk: use atomic updates for klogd work printk: Drop console_sem during panic printk: Avoid livelock with heavy printk during panic printk: disable optimistic spin during panic printk: Add panic_in_progress helper vsprintf: Move space out of string literals in fourcc_string() vsprintf: Fix potential unaligned access printk: ringbuffer: Improve prb_next_seq() performance
2 parents 30d024b + 5eb17c1 commit 3ef4ea3

File tree

5 files changed

+161
-36
lines changed

5 files changed

+161
-36
lines changed

Documentation/admin-guide/kernel-parameters.txt

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -724,6 +724,12 @@
724724
hvc<n> Use the hypervisor console device <n>. This is for
725725
both Xen and PowerPC hypervisors.
726726

727+
{ null | "" }
728+
Use to disable console output, i.e., to have kernel
729+
console messages discarded.
730+
This must be the only console= parameter used on the
731+
kernel command line.
732+
727733
If the device connected to the port is not a TTY but a braille
728734
device, prepend "brl," before the device type, for instance
729735
console=brl,ttyS0
@@ -3516,8 +3522,7 @@
35163522
difficult since unequal pointers can no longer be
35173523
compared. However, if this command-line option is
35183524
specified, then all normal pointers will have their true
3519-
value printed. Pointers printed via %pK may still be
3520-
hashed. This option should only be specified when
3525+
value printed. This option should only be specified when
35213526
debugging the kernel. Please do not use on production
35223527
kernels.
35233528

kernel/printk/printk.c

Lines changed: 76 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -93,6 +93,12 @@ EXPORT_SYMBOL_GPL(console_drivers);
9393
*/
9494
int __read_mostly suppress_printk;
9595

96+
/*
97+
* During panic, heavy printk by other CPUs can delay the
98+
* panic and risk deadlock on console resources.
99+
*/
100+
static int __read_mostly suppress_panic_printk;
101+
96102
#ifdef CONFIG_LOCKDEP
97103
static struct lockdep_map console_lock_dep_map = {
98104
.name = "console_lock"
@@ -146,8 +152,10 @@ static int __control_devkmsg(char *str)
146152

147153
static int __init control_devkmsg(char *str)
148154
{
149-
if (__control_devkmsg(str) < 0)
155+
if (__control_devkmsg(str) < 0) {
156+
pr_warn("printk.devkmsg: bad option string '%s'\n", str);
150157
return 1;
158+
}
151159

152160
/*
153161
* Set sysctl string accordingly:
@@ -166,7 +174,7 @@ static int __init control_devkmsg(char *str)
166174
*/
167175
devkmsg_log |= DEVKMSG_LOG_MASK_LOCK;
168176

169-
return 0;
177+
return 1;
170178
}
171179
__setup("printk.devkmsg=", control_devkmsg);
172180

@@ -257,6 +265,11 @@ static void __up_console_sem(unsigned long ip)
257265
}
258266
#define up_console_sem() __up_console_sem(_RET_IP_)
259267

268+
static bool panic_in_progress(void)
269+
{
270+
return unlikely(atomic_read(&panic_cpu) != PANIC_CPU_INVALID);
271+
}
272+
260273
/*
261274
* This is used for debugging the mess that is the VT code by
262275
* keeping track if we have the console semaphore held. It's
@@ -1843,6 +1856,16 @@ static int console_trylock_spinning(void)
18431856
if (console_trylock())
18441857
return 1;
18451858

1859+
/*
1860+
* It's unsafe to spin once a panic has begun. If we are the
1861+
* panic CPU, we may have already halted the owner of the
1862+
* console_sem. If we are not the panic CPU, then we should
1863+
* avoid taking console_sem, so the panic CPU has a better
1864+
* chance of cleanly acquiring it later.
1865+
*/
1866+
if (panic_in_progress())
1867+
return 0;
1868+
18461869
printk_safe_enter_irqsave(flags);
18471870

18481871
raw_spin_lock(&console_owner_lock);
@@ -2218,6 +2241,10 @@ asmlinkage int vprintk_emit(int facility, int level,
22182241
if (unlikely(suppress_printk))
22192242
return 0;
22202243

2244+
if (unlikely(suppress_panic_printk) &&
2245+
atomic_read(&panic_cpu) != raw_smp_processor_id())
2246+
return 0;
2247+
22212248
if (level == LOGLEVEL_SCHED) {
22222249
level = LOGLEVEL_DEFAULT;
22232250
in_sched = true;
@@ -2324,6 +2351,20 @@ asmlinkage __visible void early_printk(const char *fmt, ...)
23242351
}
23252352
#endif
23262353

2354+
static void set_user_specified(struct console_cmdline *c, bool user_specified)
2355+
{
2356+
if (!user_specified)
2357+
return;
2358+
2359+
/*
2360+
* @c console was defined by the user on the command line.
2361+
* Do not clear when added twice also by SPCR or the device tree.
2362+
*/
2363+
c->user_specified = true;
2364+
/* At least one console defined by the user on the command line. */
2365+
console_set_on_cmdline = 1;
2366+
}
2367+
23272368
static int __add_preferred_console(char *name, int idx, char *options,
23282369
char *brl_options, bool user_specified)
23292370
{
@@ -2340,8 +2381,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
23402381
if (strcmp(c->name, name) == 0 && c->index == idx) {
23412382
if (!brl_options)
23422383
preferred_console = i;
2343-
if (user_specified)
2344-
c->user_specified = true;
2384+
set_user_specified(c, user_specified);
23452385
return 0;
23462386
}
23472387
}
@@ -2351,7 +2391,7 @@ static int __add_preferred_console(char *name, int idx, char *options,
23512391
preferred_console = i;
23522392
strlcpy(c->name, name, sizeof(c->name));
23532393
c->options = options;
2354-
c->user_specified = user_specified;
2394+
set_user_specified(c, user_specified);
23552395
braille_set_options(c, brl_options);
23562396

23572397
c->index = idx;
@@ -2417,7 +2457,6 @@ static int __init console_setup(char *str)
24172457
*s = 0;
24182458

24192459
__add_preferred_console(buf, idx, options, brl_options, true);
2420-
console_set_on_cmdline = 1;
24212460
return 1;
24222461
}
24232462
__setup("console=", console_setup);
@@ -2573,6 +2612,25 @@ static int have_callable_console(void)
25732612
return 0;
25742613
}
25752614

2615+
/*
2616+
* Return true when this CPU should unlock console_sem without pushing all
2617+
* messages to the console. This reduces the chance that the console is
2618+
* locked when the panic CPU tries to use it.
2619+
*/
2620+
static bool abandon_console_lock_in_panic(void)
2621+
{
2622+
if (!panic_in_progress())
2623+
return false;
2624+
2625+
/*
2626+
* We can use raw_smp_processor_id() here because it is impossible for
2627+
* the task to be migrated to the panic_cpu, or away from it. If
2628+
* panic_cpu has already been set, and we're not currently executing on
2629+
* that CPU, then we never will be.
2630+
*/
2631+
return atomic_read(&panic_cpu) != raw_smp_processor_id();
2632+
}
2633+
25762634
/*
25772635
* Can we actually use the console at this time on this cpu?
25782636
*
@@ -2603,6 +2661,7 @@ void console_unlock(void)
26032661
{
26042662
static char ext_text[CONSOLE_EXT_LOG_MAX];
26052663
static char text[CONSOLE_LOG_MAX];
2664+
static int panic_console_dropped;
26062665
unsigned long flags;
26072666
bool do_cond_resched, retry;
26082667
struct printk_info info;
@@ -2657,6 +2716,10 @@ void console_unlock(void)
26572716
if (console_seq != r.info->seq) {
26582717
console_dropped += r.info->seq - console_seq;
26592718
console_seq = r.info->seq;
2719+
if (panic_in_progress() && panic_console_dropped++ > 10) {
2720+
suppress_panic_printk = 1;
2721+
pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
2722+
}
26602723
}
26612724

26622725
if (suppress_message_printing(r.info->level)) {
@@ -2716,6 +2779,10 @@ void console_unlock(void)
27162779
if (handover)
27172780
return;
27182781

2782+
/* Allow panic_cpu to take over the consoles safely */
2783+
if (abandon_console_lock_in_panic())
2784+
break;
2785+
27192786
if (do_cond_resched)
27202787
cond_resched();
27212788
}
@@ -2733,7 +2800,7 @@ void console_unlock(void)
27332800
* flush, no worries.
27342801
*/
27352802
retry = prb_read_valid(prb, next_seq, NULL);
2736-
if (retry && console_trylock())
2803+
if (retry && !abandon_console_lock_in_panic() && console_trylock())
27372804
goto again;
27382805
}
27392806
EXPORT_SYMBOL(console_unlock);
@@ -3228,7 +3295,7 @@ static DEFINE_PER_CPU(int, printk_pending);
32283295

32293296
static void wake_up_klogd_work_func(struct irq_work *irq_work)
32303297
{
3231-
int pending = __this_cpu_xchg(printk_pending, 0);
3298+
int pending = this_cpu_xchg(printk_pending, 0);
32323299

32333300
if (pending & PRINTK_PENDING_OUTPUT) {
32343301
/* If trylock fails, someone else is doing the printing */
@@ -3262,7 +3329,7 @@ void defer_console_output(void)
32623329
return;
32633330

32643331
preempt_disable();
3265-
__this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT);
3332+
this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT);
32663333
irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
32673334
preempt_enable();
32683335
}

kernel/printk/printk_ringbuffer.c

Lines changed: 47 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -474,8 +474,10 @@ static enum desc_state desc_read(struct prb_desc_ring *desc_ring,
474474
* state has been re-checked. A memcpy() for all of @desc
475475
* cannot be used because of the atomic_t @state_var field.
476476
*/
477-
memcpy(&desc_out->text_blk_lpos, &desc->text_blk_lpos,
478-
sizeof(desc_out->text_blk_lpos)); /* LMM(desc_read:C) */
477+
if (desc_out) {
478+
memcpy(&desc_out->text_blk_lpos, &desc->text_blk_lpos,
479+
sizeof(desc_out->text_blk_lpos)); /* LMM(desc_read:C) */
480+
}
479481
if (seq_out)
480482
*seq_out = info->seq; /* also part of desc_read:C */
481483
if (caller_id_out)
@@ -528,7 +530,8 @@ static enum desc_state desc_read(struct prb_desc_ring *desc_ring,
528530
state_val = atomic_long_read(state_var); /* LMM(desc_read:E) */
529531
d_state = get_desc_state(id, state_val);
530532
out:
531-
atomic_long_set(&desc_out->state_var, state_val);
533+
if (desc_out)
534+
atomic_long_set(&desc_out->state_var, state_val);
532535
return d_state;
533536
}
534537

@@ -1449,6 +1452,9 @@ static void desc_make_final(struct prb_desc_ring *desc_ring, unsigned long id)
14491452

14501453
atomic_long_cmpxchg_relaxed(&d->state_var, prev_state_val,
14511454
DESC_SV(id, desc_finalized)); /* LMM(desc_make_final:A) */
1455+
1456+
/* Best effort to remember the last finalized @id. */
1457+
atomic_long_set(&desc_ring->last_finalized_id, id);
14521458
}
14531459

14541460
/**
@@ -1657,7 +1663,12 @@ void prb_commit(struct prb_reserved_entry *e)
16571663
*/
16581664
void prb_final_commit(struct prb_reserved_entry *e)
16591665
{
1666+
struct prb_desc_ring *desc_ring = &e->rb->desc_ring;
1667+
16601668
_prb_commit(e, desc_finalized);
1669+
1670+
/* Best effort to remember the last finalized @id. */
1671+
atomic_long_set(&desc_ring->last_finalized_id, e->id);
16611672
}
16621673

16631674
/*
@@ -2005,9 +2016,39 @@ u64 prb_first_valid_seq(struct printk_ringbuffer *rb)
20052016
*/
20062017
u64 prb_next_seq(struct printk_ringbuffer *rb)
20072018
{
2008-
u64 seq = 0;
2019+
struct prb_desc_ring *desc_ring = &rb->desc_ring;
2020+
enum desc_state d_state;
2021+
unsigned long id;
2022+
u64 seq;
2023+
2024+
/* Check if the cached @id still points to a valid @seq. */
2025+
id = atomic_long_read(&desc_ring->last_finalized_id);
2026+
d_state = desc_read(desc_ring, id, NULL, &seq, NULL);
20092027

2010-
/* Search forward from the oldest descriptor. */
2028+
if (d_state == desc_finalized || d_state == desc_reusable) {
2029+
/*
2030+
* Begin searching after the last finalized record.
2031+
*
2032+
* On 0, the search must begin at 0 because of hack#2
2033+
* of the bootstrapping phase it is not known if a
2034+
* record at index 0 exists.
2035+
*/
2036+
if (seq != 0)
2037+
seq++;
2038+
} else {
2039+
/*
2040+
* The information about the last finalized sequence number
2041+
* has gone. It should happen only when there is a flood of
2042+
* new messages and the ringbuffer is rapidly recycled.
2043+
* Give up and start from the beginning.
2044+
*/
2045+
seq = 0;
2046+
}
2047+
2048+
/*
2049+
* The information about the last finalized @seq might be inaccurate.
2050+
* Search forward to find the current one.
2051+
*/
20112052
while (_prb_read_valid(rb, &seq, NULL, NULL))
20122053
seq++;
20132054

@@ -2044,6 +2085,7 @@ void prb_init(struct printk_ringbuffer *rb,
20442085
rb->desc_ring.infos = infos;
20452086
atomic_long_set(&rb->desc_ring.head_id, DESC0_ID(descbits));
20462087
atomic_long_set(&rb->desc_ring.tail_id, DESC0_ID(descbits));
2088+
atomic_long_set(&rb->desc_ring.last_finalized_id, DESC0_ID(descbits));
20472089

20482090
rb->text_data_ring.size_bits = textbits;
20492091
rb->text_data_ring.data = text_buf;

kernel/printk/printk_ringbuffer.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -75,6 +75,7 @@ struct prb_desc_ring {
7575
struct printk_info *infos;
7676
atomic_long_t head_id;
7777
atomic_long_t tail_id;
78+
atomic_long_t last_finalized_id;
7879
};
7980

8081
/*
@@ -258,6 +259,7 @@ static struct printk_ringbuffer name = { \
258259
.infos = &_##name##_infos[0], \
259260
.head_id = ATOMIC_INIT(DESC0_ID(descbits)), \
260261
.tail_id = ATOMIC_INIT(DESC0_ID(descbits)), \
262+
.last_finalized_id = ATOMIC_INIT(DESC0_ID(descbits)), \
261263
}, \
262264
.text_data_ring = { \
263265
.size_bits = (avgtextbits) + (descbits), \

0 commit comments

Comments
 (0)