printk() – It’s Old, What Can We Do to Make It Young Again? – Steven Rostedt, VMware & Sergey Senozhatsky, Samsung Electronics

Sergey made the patches, Steven is the reviewer, so Sergey did the presentation.

printk() is complicated. It takes a number of locks, which ones exactly depends on your .config. In addition, you can do printk() from an NMI that interrupted an NMI. It is easy to deadlock, e.g. printk() may take the scheduler spinlock, so you can’t use it in the scheduler when that lock is taken already. lockdep as well: reporting a deadlock will call printk() again. Therefore, for a long time printk() idd lockdep_off() and disables the RCU validator.

So printk_safe was created. This allows printk() to be reentrant, enables lockdep again in printk(), and generally make printk() less deadlock prone. But it’s not quite reentrant yet. printk_safe() can’t be called from sleeping context.

The fundamental prolbem is that printk depends on two different types of locks: locks internal to printk, and locks that come from somewhere else (e.g. locks in the serial driver). A solution would be to do printk_deferred() everywhere, which means just one internal lock. But the actual printing has to be done somewhere, and in bad lockup scenarios there is no guarantee that e.g. IRQ context will ever arrive again. Alternatively, we could fallback on early_printk which doesn’t do locking but breaks e.g. dmesg. For example, add a write_on_panic() callback to the console struct that is completely lockless and can’t be called from any context except panic().

There used to be zap_locks() in printk that would drop locks when it detects recursion, but that only looked at the internal locks while the external ones are actually the tricky ones. Since there is now a better way of handling recursion, the function is removed. However, the zap_locks() approach could be used in console drivers. Add a zap_locks() member and call it from panic context so that you can re-enter the write() function.

It could also be possible to remove locking from the console drivers, i.e. the console functions don’t do any locking themselves, the callers do, by calling a lock()/unlock() member.

console_sem is used for a lot more than printk(). printk() uses it to make sure the print happens only on a single CPU. The console also uses it to handle line wrapping, UTF8 encoding, avoid mixing with TTY processing, cursor blinking, avoiding race between printk() from user context and printk() from IRQ, … Also for non-printk() related things: power management, adding/removing consoles. Some of these can schedule() with console_sem held. This means that in a livelock situation, printk() won’t come out again because it won’t acquire the console_sem.

The problem is that printk() is a mix of different subsystems: framebuffers, serial ports, TTY, sched, timekeeping, …. Maybe it’s time for a new printk() API. Change into a polling API: printk just goes into a buffer, and the consoles poll the log buffer. This allows to remove console_sem. This is in fact how serial drivers work already: they transmit xmit characters out of their buffer. This might even work with not all consoles working in polling mode. The problem is that there is no immediate flush, so when printk() returns the message is not printed yet.

printk() makes sure there is just one CPU printing the buffer, the other CPUs just append to the buffer. The printing CPU continues printing until the buffer is empty. However, if the printing CPU is in atomic context, IRQ, you’re adding unbounded latency which is some kind of lockup. So you’d like some preemption points in there. But that doesn’t solve all problems, and also slows printk() down which is an issue for e.g. OOM print which slows down OOM killer. So for some people it’s actually making things worse. Again, polling could be a solution, but now from printk_thread, but that didn’t work. People really want to have direct printk(), because you want it when your system dies.














Leave a Reply

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s