Re: [PATCH v11 3/3] printk: make printk.synchronous param rw

[Petr Mladek <pmladek@suse.com>]

On Fri 2016-04-08 14:29:27, Sergey Senozhatsky wrote:
> On (04/08/16 12:04), Pan Xinhui wrote:
> [..]
> > > +/*
> > > + * Init async printk via late_initcall, after core/arch/device/etc.
> > > + * initialization.
> > > + */
> > > +static __init int init_printk_kthread(void)
> > > +{
> > > +	printk_initcall_done = true;
> > > +	return __init_printk_kthread();
> > hello, 
> > 
> > One confusion, Why not use a lock to protect __init_printk_kthread from parallel call? Otherwise I think there is a race.
> > But for simplicity, maybe you could write codes as below.
> > 
> > +	int ret  = __init_printk_kthread();
> > +	printk_initcall_done = true;
> > +	return ret;
> > 
> > In my opinion, using a lock is better.
> 
> Hello,
> 
> I though about this, but isn't late_initcall() happening before kernel
> starts /sbin/init? who can race with
> 
> 	late_initcall() -> init_printk_kthread() -> __init_printk_kthread()?
> 
> looking at
> 
> static int __ref kernel_init(void *unused)
> {
>         int ret;
> 
>         kernel_init_freeable();
>         /* need to finish all async __init code before freeing the memory */
>         async_synchronize_full();
>         free_initmem();
> ..
> 
>         if (!try_to_run_init_process("/sbin/init") ||
>             !try_to_run_init_process("/etc/init") ||
>             !try_to_run_init_process("/bin/init") ||
>             !try_to_run_init_process("/bin/sh"))
>                 return 0;
> 
> __init (and init_printk_kthread is __init) is finished and freed by the
> time kernel try_to_run_init_process. isn't it?

Please, what is the purpose of "printk_initcall_done" then? If I get
this correctly, it will always be true when printk_sync_set() is
called.


> sysfs knob -> __init_printk_kthread() is protected by printk_sync_lock
> mutex, obviously there can be parallel calls from user space.

I think that this could not happen. We have discussed similar problem
with livepatching some time ago. AFAIK, writes to sysfs are
synchronized out of box.

Huh, the code is not trivial, so I rather generated a backtrace to be
on the safe side:

[  370.628592] WARNING: CPU: 2 PID: 3768 at kernel/printk/printk.c:2827 printk_sync_set+0x42/0x70
[  370.628593] Modules linked in:
[  370.628597] CPU: 2 PID: 3768 Comm: bash Not tainted 4.6.0-rc4-4-default+ #2691
[  370.628599] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
[  370.628600]  0000000000000000 ffff88003709fd28 ffffffff814206fc 0000000000000000
[  370.628604]  0000000000000000 ffff88003709fd68 ffffffff8106b4e1 00000b0b00000246
[  370.628606]  0000000000000000 ffffffff81dbce18 ffff88013923a3e0 ffff88013a705c80
[  370.628609] Call Trace:
[  370.628614]  [<ffffffff814206fc>] dump_stack+0x85/0xc9
[  370.628617]  [<ffffffff8106b4e1>] __warn+0xd1/0xf0
[  370.628619]  [<ffffffff8106b5cd>] warn_slowpath_null+0x1d/0x20
[  370.628621]  [<ffffffff810d4112>] printk_sync_set+0x42/0x70
[  370.628624]  [<ffffffff8108ecfa>] param_attr_store+0x6a/0xd0
[  370.628627]  [<ffffffff8108dffd>] module_attr_store+0x1d/0x30
[  370.628631]  [<ffffffff8129ad44>] sysfs_kf_write+0x44/0x60
[  370.628634]  [<ffffffff8129a344>] kernfs_fop_write+0x144/0x190
[  370.628637]  [<ffffffff81214e08>] __vfs_write+0x28/0xe0
[  370.628641]  [<ffffffff810c04e9>] ? percpu_down_read+0x49/0x80
[  370.628643]  [<ffffffff81218fc1>] ? __sb_start_write+0xd1/0xf0
[  370.628645]  [<ffffffff81218fc1>] ? __sb_start_write+0xd1/0xf0
[  370.628647]  [<ffffffff81215d12>] vfs_write+0xa2/0x1a0
[  370.628650]  [<ffffffff812362b6>] ? __fget_light+0x66/0x90
[  370.628652]  [<ffffffff81217089>] SyS_write+0x49/0xa0
[  370.628656]  [<ffffffff8191c37c>] entry_SYSCALL_64_fastpath+0x1f/0xbd
[  370.628658] ---[ end trace eb22d849233b4c4c ]---

and the writes are really synchronized. At least here:

kernfs_fop_write()
  mutex_lock(&of->mutex)
     ops->write()
  mutex_unlock(&of->mutex);

It means that the printk_sync_lock is superfluous.


Otherwise the patch looks fine. I am bit concerned because
the synchronization between the setting and testing of
printk_sync/printk_kthread is a bit weak. But it works
because we always either wakeup the kthread or call
the console directly. So, we are on the safe side.


Best Regards,
Petr

PS: I am sorry for the late comment. I was not able to do so
immediately and I wrongly marked the mail as read :-(