Re: [PATCH] printk: rebalance printk

From: Pan Xinhui
Date: Tue Aug 11 2015 - 22:22:45 EST




On 2015å08æ12æ 10:04, Greg Kroah-Hartman wrote:
> On Wed, Aug 12, 2015 at 09:53:58AM +0800, Pan Xinhui wrote:
>> Hi, Greg
>> thanks for your reply!
>> On 2015å08æ12æ 02:16, Greg Kroah-Hartman wrote:
>>> On Tue, Aug 11, 2015 at 07:23:01PM +0800, Pan Xinhui wrote:
>>>> From: Pan Xinhui <xinhuix.pan@xxxxxxxxx>
>>>>
>>>> printk can be called in any context, It's very useful to output debug
>>>> info.
>>>>
>>>> But it might cause very bad issues on some special cases. For example,
>>>> some driver hit errors, and it dumps many messages like reg values, etc.
>>>>
>>>> Sometimes, printk is called when irqs disabled. This is OKay if there is
>>>> a few messages. But What would happen if many messages outputted by other
>>>> drivers at same time.
>>>>
>>>> Here is the scenario.
>>>> CPUA CPUB
>>>> local_irq_save(flags);
>>>> printk()
>>>> while(..) { --> console_unlock
>>>> printk(...);
>>>> //hundreds or thousands loops
>>>> } //all messages flushed out to consoles
>>>> local_irq_restore(flags);
>>>>
>>>
>>> Where are you seeing this type of scenario "in the wild"? Or is this
>>> just a "debug/bringup hardware" issue? We shouldn't be ever stuck in a
>>> printk that prints hundreds or thousands of loops, if so, we need to fix
>>> the kernel code that does that, as we do have control over this.
>>>
>>
>> Sorry for misleading. these loops are just an example. In real world,
>> there are many pr_info/pr_err when some drivers hit device errors to
>> dump debug information.
>
> That's not good, they should use dev_dbg() for that instead.
>
Agree, We changed some codes to use dev_dbg(). But some errors still need be outputted immediately.
But when we enabled dynamic debug. there is not much difference... printk issue still hit.

>> There is camera and sound test(multimedia test) in our side, we enable
>> dynamic_debug to collect logs to fix some weird issues. sound driver
>> will dump many reg/memory values, and camera will output a few logs
>> with irqs disabled. So we hit this printk issues very frequently, and
>> it blocks our tests indeed.
>
> Maybe those memory value dumps should be done through debugfs instead of
> printk?
>
These reg/memory runtime values must be outputted in time, they have changed at any time..

>> As printk is announced that it could be used in most context, So I
>> prefer to enhance the stability of printk to handle such case.
>
> Stability is nice, but using printk for things it was never ment to be
> used for, isn't good. Especially if you are forced to add additional
> complexity to the printk logic just for these corner cases that no one
> uses :)
>

printk is very good, it does work in very complex context, including in interrupt, etc.
However if we could make it better, then why not :)

My patch is a little complex. Sorry for that.
I would try to work out V2.

thanks
xinhui

> thanks,
>
> greg k-h
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/