Skip to content

Commit b054677

Browse files
committed
Merge tag 'printk-for-6.9' of git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux
Pull printk updates from Petr Mladek: "Improve the behavior during panic. The issues were found when testing the ongoing changes introducing atomic consoles and printk kthreads: - pr_flush() has to wait for the last reserved record instead of the last finalized one. Note that records are finalized in random order when generated by more CPUs in parallel. - Ignore non-finalized records during panic(). Messages printed on panic-CPU are always finalized. Messages printed by other CPUs might never be finalized when the CPUs get stopped. - Block new printk() calls on non-panic CPUs completely. Backtraces are printed before entering the panic mode. Later messages would just mess information printed by the panic CPU. - Do not take console_lock in console_flush_on_panic() at all. The original code did try_lock()/console_unlock(). The unlock part might cause a deadlock when panic() happened in a scheduler code. - Fix conversion of 64-bit sequence number for 32-bit atomic operations" * tag 'printk-for-6.9' of git://git.kernel.org/pub/scm/linux/kernel/git/printk/linux: dump_stack: Do not get cpu_sync for panic CPU panic: Flush kernel log buffer at the end printk: Avoid non-panic CPUs writing to ringbuffer printk: Disable passing console lock owner completely during panic() printk: ringbuffer: Skip non-finalized records in panic printk: Wait for all reserved records with pr_flush() printk: ringbuffer: Cleanup reader terminology printk: Add this_cpu_in_panic() printk: For @suppress_panic_printk check for other CPU in panic printk: ringbuffer: Clarify special lpos values printk: ringbuffer: Do not skip non-finalized records with prb_next_seq() printk: Use prb_first_seq() as base for 32bit seq macros printk: Adjust mapping for 32bit seq macros printk: nbcon: Relocate 32bit seq macros
2 parents f88c3fb + 7412dc6 commit b054677

File tree

7 files changed

+419
-138
lines changed

7 files changed

+419
-138
lines changed

include/linux/printk.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -273,6 +273,8 @@ static inline void printk_trigger_flush(void)
273273
}
274274
#endif
275275

276+
bool this_cpu_in_panic(void);
277+
276278
#ifdef CONFIG_SMP
277279
extern int __printk_cpu_sync_try_get(void);
278280
extern void __printk_cpu_sync_wait(void);

kernel/panic.c

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -446,6 +446,14 @@ void panic(const char *fmt, ...)
446446

447447
/* Do not scroll important messages printed above */
448448
suppress_printk = 1;
449+
450+
/*
451+
* The final messages may not have been printed if in a context that
452+
* defers printing (such as NMI) and irq_work is not available.
453+
* Explicitly flush the kernel log buffer one last time.
454+
*/
455+
console_flush_on_panic(CONSOLE_FLUSH_PENDING);
456+
449457
local_irq_enable();
450458
for (i = 0; ; i += PANIC_TIMER_STEP) {
451459
touch_softlockup_watchdog();

kernel/printk/nbcon.c

Lines changed: 4 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -140,39 +140,6 @@ static inline bool nbcon_state_try_cmpxchg(struct console *con, struct nbcon_sta
140140
return atomic_try_cmpxchg(&ACCESS_PRIVATE(con, nbcon_state), &cur->atom, new->atom);
141141
}
142142

143-
#ifdef CONFIG_64BIT
144-
145-
#define __seq_to_nbcon_seq(seq) (seq)
146-
#define __nbcon_seq_to_seq(seq) (seq)
147-
148-
#else /* CONFIG_64BIT */
149-
150-
#define __seq_to_nbcon_seq(seq) ((u32)seq)
151-
152-
static inline u64 __nbcon_seq_to_seq(u32 nbcon_seq)
153-
{
154-
u64 seq;
155-
u64 rb_next_seq;
156-
157-
/*
158-
* The provided sequence is only the lower 32 bits of the ringbuffer
159-
* sequence. It needs to be expanded to 64bit. Get the next sequence
160-
* number from the ringbuffer and fold it.
161-
*
162-
* Having a 32bit representation in the console is sufficient.
163-
* If a console ever gets more than 2^31 records behind
164-
* the ringbuffer then this is the least of the problems.
165-
*
166-
* Also the access to the ring buffer is always safe.
167-
*/
168-
rb_next_seq = prb_next_seq(prb);
169-
seq = rb_next_seq - ((u32)rb_next_seq - nbcon_seq);
170-
171-
return seq;
172-
}
173-
174-
#endif /* CONFIG_64BIT */
175-
176143
/**
177144
* nbcon_seq_read - Read the current console sequence
178145
* @con: Console to read the sequence of
@@ -183,7 +150,7 @@ u64 nbcon_seq_read(struct console *con)
183150
{
184151
unsigned long nbcon_seq = atomic_long_read(&ACCESS_PRIVATE(con, nbcon_seq));
185152

186-
return __nbcon_seq_to_seq(nbcon_seq);
153+
return __ulseq_to_u64seq(prb, nbcon_seq);
187154
}
188155

189156
/**
@@ -204,7 +171,7 @@ void nbcon_seq_force(struct console *con, u64 seq)
204171
*/
205172
u64 valid_seq = max_t(u64, seq, prb_first_valid_seq(prb));
206173

207-
atomic_long_set(&ACCESS_PRIVATE(con, nbcon_seq), __seq_to_nbcon_seq(valid_seq));
174+
atomic_long_set(&ACCESS_PRIVATE(con, nbcon_seq), __u64seq_to_ulseq(valid_seq));
208175

209176
/* Clear con->seq since nbcon consoles use con->nbcon_seq instead. */
210177
con->seq = 0;
@@ -223,11 +190,11 @@ void nbcon_seq_force(struct console *con, u64 seq)
223190
*/
224191
static void nbcon_seq_try_update(struct nbcon_context *ctxt, u64 new_seq)
225192
{
226-
unsigned long nbcon_seq = __seq_to_nbcon_seq(ctxt->seq);
193+
unsigned long nbcon_seq = __u64seq_to_ulseq(ctxt->seq);
227194
struct console *con = ctxt->console;
228195

229196
if (atomic_long_try_cmpxchg(&ACCESS_PRIVATE(con, nbcon_seq), &nbcon_seq,
230-
__seq_to_nbcon_seq(new_seq))) {
197+
__u64seq_to_ulseq(new_seq))) {
231198
ctxt->seq = new_seq;
232199
} else {
233200
ctxt->seq = nbcon_seq_read(con);

kernel/printk/printk.c

Lines changed: 59 additions & 42 deletions
Original file line numberDiff line numberDiff line change
@@ -347,6 +347,29 @@ static bool panic_in_progress(void)
347347
return unlikely(atomic_read(&panic_cpu) != PANIC_CPU_INVALID);
348348
}
349349

350+
/* Return true if a panic is in progress on the current CPU. */
351+
bool this_cpu_in_panic(void)
352+
{
353+
/*
354+
* We can use raw_smp_processor_id() here because it is impossible for
355+
* the task to be migrated to the panic_cpu, or away from it. If
356+
* panic_cpu has already been set, and we're not currently executing on
357+
* that CPU, then we never will be.
358+
*/
359+
return unlikely(atomic_read(&panic_cpu) == raw_smp_processor_id());
360+
}
361+
362+
/*
363+
* Return true if a panic is in progress on a remote CPU.
364+
*
365+
* On true, the local CPU should immediately release any printing resources
366+
* that may be needed by the panic CPU.
367+
*/
368+
bool other_cpu_in_panic(void)
369+
{
370+
return (panic_in_progress() && !this_cpu_in_panic());
371+
}
372+
350373
/*
351374
* This is used for debugging the mess that is the VT code by
352375
* keeping track if we have the console semaphore held. It's
@@ -439,12 +462,6 @@ static int console_msg_format = MSG_FORMAT_DEFAULT;
439462
static DEFINE_MUTEX(syslog_lock);
440463

441464
#ifdef CONFIG_PRINTK
442-
/*
443-
* During panic, heavy printk by other CPUs can delay the
444-
* panic and risk deadlock on console resources.
445-
*/
446-
static int __read_mostly suppress_panic_printk;
447-
448465
DECLARE_WAIT_QUEUE_HEAD(log_wait);
449466
/* All 3 protected by @syslog_lock. */
450467
/* the next printk record to read by syslog(READ) or /proc/kmsg */
@@ -1835,10 +1852,23 @@ static bool console_waiter;
18351852
*/
18361853
static void console_lock_spinning_enable(void)
18371854
{
1855+
/*
1856+
* Do not use spinning in panic(). The panic CPU wants to keep the lock.
1857+
* Non-panic CPUs abandon the flush anyway.
1858+
*
1859+
* Just keep the lockdep annotation. The panic-CPU should avoid
1860+
* taking console_owner_lock because it might cause a deadlock.
1861+
* This looks like the easiest way how to prevent false lockdep
1862+
* reports without handling races a lockless way.
1863+
*/
1864+
if (panic_in_progress())
1865+
goto lockdep;
1866+
18381867
raw_spin_lock(&console_owner_lock);
18391868
console_owner = current;
18401869
raw_spin_unlock(&console_owner_lock);
18411870

1871+
lockdep:
18421872
/* The waiter may spin on us after setting console_owner */
18431873
spin_acquire(&console_owner_dep_map, 0, 0, _THIS_IP_);
18441874
}
@@ -1863,6 +1893,22 @@ static int console_lock_spinning_disable_and_check(int cookie)
18631893
{
18641894
int waiter;
18651895

1896+
/*
1897+
* Ignore spinning waiters during panic() because they might get stopped
1898+
* or blocked at any time,
1899+
*
1900+
* It is safe because nobody is allowed to start spinning during panic
1901+
* in the first place. If there has been a waiter then non panic CPUs
1902+
* might stay spinning. They would get stopped anyway. The panic context
1903+
* will never start spinning and an interrupted spin on panic CPU will
1904+
* never continue.
1905+
*/
1906+
if (panic_in_progress()) {
1907+
/* Keep lockdep happy. */
1908+
spin_release(&console_owner_dep_map, _THIS_IP_);
1909+
return 0;
1910+
}
1911+
18661912
raw_spin_lock(&console_owner_lock);
18671913
waiter = READ_ONCE(console_waiter);
18681914
console_owner = NULL;
@@ -2259,8 +2305,12 @@ asmlinkage int vprintk_emit(int facility, int level,
22592305
if (unlikely(suppress_printk))
22602306
return 0;
22612307

2262-
if (unlikely(suppress_panic_printk) &&
2263-
atomic_read(&panic_cpu) != raw_smp_processor_id())
2308+
/*
2309+
* The messages on the panic CPU are the most important. If
2310+
* non-panic CPUs are generating any messages, they will be
2311+
* silently dropped.
2312+
*/
2313+
if (other_cpu_in_panic())
22642314
return 0;
22652315

22662316
if (level == LOGLEVEL_SCHED) {
@@ -2590,26 +2640,6 @@ static int console_cpu_notify(unsigned int cpu)
25902640
return 0;
25912641
}
25922642

2593-
/*
2594-
* Return true if a panic is in progress on a remote CPU.
2595-
*
2596-
* On true, the local CPU should immediately release any printing resources
2597-
* that may be needed by the panic CPU.
2598-
*/
2599-
bool other_cpu_in_panic(void)
2600-
{
2601-
if (!panic_in_progress())
2602-
return false;
2603-
2604-
/*
2605-
* We can use raw_smp_processor_id() here because it is impossible for
2606-
* the task to be migrated to the panic_cpu, or away from it. If
2607-
* panic_cpu has already been set, and we're not currently executing on
2608-
* that CPU, then we never will be.
2609-
*/
2610-
return atomic_read(&panic_cpu) != raw_smp_processor_id();
2611-
}
2612-
26132643
/**
26142644
* console_lock - block the console subsystem from printing
26152645
*
@@ -2765,8 +2795,6 @@ void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
27652795
bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
27662796
bool is_extended, bool may_suppress)
27672797
{
2768-
static int panic_console_dropped;
2769-
27702798
struct printk_buffers *pbufs = pmsg->pbufs;
27712799
const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
27722800
const size_t outbuf_sz = sizeof(pbufs->outbuf);
@@ -2794,17 +2822,6 @@ bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
27942822
pmsg->seq = r.info->seq;
27952823
pmsg->dropped = r.info->seq - seq;
27962824

2797-
/*
2798-
* Check for dropped messages in panic here so that printk
2799-
* suppression can occur as early as possible if necessary.
2800-
*/
2801-
if (pmsg->dropped &&
2802-
panic_in_progress() &&
2803-
panic_console_dropped++ > 10) {
2804-
suppress_panic_printk = 1;
2805-
pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
2806-
}
2807-
28082825
/* Skip record that has level above the console loglevel. */
28092826
if (may_suppress && suppress_message_printing(r.info->level))
28102827
goto out;
@@ -3750,7 +3767,7 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
37503767

37513768
might_sleep();
37523769

3753-
seq = prb_next_seq(prb);
3770+
seq = prb_next_reserve_seq(prb);
37543771

37553772
/* Flush the consoles so that records up to @seq are printed. */
37563773
console_lock();

0 commit comments

Comments
 (0)