[RESEND] lib/test_printf.c: call wait_for_random_bytes() before plain %p tests

Message ID 20180604113708.11554-1-thierry.escande@linaro.org
State New
Headers show
Series
  • [RESEND] lib/test_printf.c: call wait_for_random_bytes() before plain %p tests
Related show

Commit Message

Thierry Escande June 4, 2018, 11:37 a.m.
If the test_printf module is loaded before the crng is initialized, the
plain 'p' tests will fail because the printed address will not be hashed
and the buffer will contain '(ptrval)' instead.
This patch adds a call to wait_for_random_bytes() before plain 'p' tests
to make sure the crng is initialized.

Signed-off-by: Thierry Escande <thierry.escande@linaro.org>

Acked-by: Tobin C. Harding <me@tobin.cc>

---
 lib/test_printf.c | 7 +++++++
 1 file changed, 7 insertions(+)

-- 
2.14.1

Comments

Andy Shevchenko June 5, 2018, 12:43 p.m. | #1
+Cc: Petr. I suppose test_printf is going through his tree as well as
vsnprintf itself. At least it logically makes sense.

On Mon, Jun 4, 2018 at 2:37 PM, Thierry Escande
<thierry.escande@linaro.org> wrote:
> If the test_printf module is loaded before the crng is initialized, the

> plain 'p' tests will fail because the printed address will not be hashed

> and the buffer will contain '(ptrval)' instead.

> This patch adds a call to wait_for_random_bytes() before plain 'p' tests

> to make sure the crng is initialized.

>

> Signed-off-by: Thierry Escande <thierry.escande@linaro.org>

> Acked-by: Tobin C. Harding <me@tobin.cc>

> ---

>  lib/test_printf.c | 7 +++++++

>  1 file changed, 7 insertions(+)

>

> diff --git a/lib/test_printf.c b/lib/test_printf.c

> index 71ebfa43ad05..839be9385a8a 100644

> --- a/lib/test_printf.c

> +++ b/lib/test_printf.c

> @@ -260,6 +260,13 @@ plain(void)

>  {

>         int err;

>

> +       /*

> +        * Make sure crng is ready. Otherwise we get "(ptrval)" instead

> +        * of a hashed address when printing '%p' in plain_hash() and

> +        * plain_format().

> +        */

> +       wait_for_random_bytes();

> +

>         err = plain_hash();

>         if (err) {

>                 pr_warn("plain 'p' does not appear to be hashed\n");

> --

> 2.14.1

>




-- 
With Best Regards,
Andy Shevchenko
Petr Mladek June 7, 2018, 12:24 p.m. | #2
On Mon 2018-06-04 13:37:08, Thierry Escande wrote:
> If the test_printf module is loaded before the crng is initialized, the

> plain 'p' tests will fail because the printed address will not be hashed

> and the buffer will contain '(ptrval)' instead.

> This patch adds a call to wait_for_random_bytes() before plain 'p' tests

> to make sure the crng is initialized.


Hmm, my system did not boot with this patch and
CONFIG_TEST_PRINTF=y

I guess that there was not enough entropy. It is basically a deadlock.
The build-in module init calls are called when SMP is enabled but
there is no real activity and the init calls are called sequentially.
Therefore there is nothing that could produce some entropy, ...

I suggest to skip the test when crng is not ready.

Best Regards,
Petr

> Signed-off-by: Thierry Escande <thierry.escande@linaro.org>

> Acked-by: Tobin C. Harding <me@tobin.cc>

> ---

>  lib/test_printf.c | 7 +++++++

>  1 file changed, 7 insertions(+)

> 

> diff --git a/lib/test_printf.c b/lib/test_printf.c

> index 71ebfa43ad05..839be9385a8a 100644

> --- a/lib/test_printf.c

> +++ b/lib/test_printf.c

> @@ -260,6 +260,13 @@ plain(void)

>  {

>  	int err;

>  

> +	/*

> +	 * Make sure crng is ready. Otherwise we get "(ptrval)" instead

> +	 * of a hashed address when printing '%p' in plain_hash() and

> +	 * plain_format().

> +	 */

> +	wait_for_random_bytes();

> +

>  	err = plain_hash();

>  	if (err) {

>  		pr_warn("plain 'p' does not appear to be hashed\n");

> -- 

> 2.14.1

>
Thierry Escande June 7, 2018, 6:47 p.m. | #3
Hi Petr,

On 07/06/2018 14:24, Petr Mladek wrote:
> On Mon 2018-06-04 13:37:08, Thierry Escande wrote:

>> If the test_printf module is loaded before the crng is initialized, the

>> plain 'p' tests will fail because the printed address will not be hashed

>> and the buffer will contain '(ptrval)' instead.

>> This patch adds a call to wait_for_random_bytes() before plain 'p' tests

>> to make sure the crng is initialized.

> 

> Hmm, my system did not boot with this patch and

> CONFIG_TEST_PRINTF=y

> 

> I guess that there was not enough entropy. It is basically a deadlock.

> The build-in module init calls are called when SMP is enabled but

> there is no real activity and the init calls are called sequentially.

> Therefore there is nothing that could produce some entropy, ...

> 

> I suggest to skip the test when crng is not ready.


Thanks for pointing this out.

The issue is that the crng_ready() is not available outside of random.c. 
I'll leave the call to wait_for_random_bytes() if test_printf is 
compiled as a module and use add_random_ready_callback() to check if 
crng is initialized otherwise. Does that sound ok to you?

Regards,
Thierry

> 

> Best Regards,

> Petr

> 

>> Signed-off-by: Thierry Escande <thierry.escande@linaro.org>

>> Acked-by: Tobin C. Harding <me@tobin.cc>

>> ---

>>   lib/test_printf.c | 7 +++++++

>>   1 file changed, 7 insertions(+)

>>

>> diff --git a/lib/test_printf.c b/lib/test_printf.c

>> index 71ebfa43ad05..839be9385a8a 100644

>> --- a/lib/test_printf.c

>> +++ b/lib/test_printf.c

>> @@ -260,6 +260,13 @@ plain(void)

>>   {

>>   	int err;

>>   

>> +	/*

>> +	 * Make sure crng is ready. Otherwise we get "(ptrval)" instead

>> +	 * of a hashed address when printing '%p' in plain_hash() and

>> +	 * plain_format().

>> +	 */

>> +	wait_for_random_bytes();

>> +

>>   	err = plain_hash();

>>   	if (err) {

>>   		pr_warn("plain 'p' does not appear to be hashed\n");

>> -- 

>> 2.14.1

>>
Petr Mladek June 8, 2018, 8:04 a.m. | #4
On Thu 2018-06-07 20:47:25, Thierry Escande wrote:
> Hi Petr,

> 

> On 07/06/2018 14:24, Petr Mladek wrote:

> > On Mon 2018-06-04 13:37:08, Thierry Escande wrote:

> > > If the test_printf module is loaded before the crng is initialized, the

> > > plain 'p' tests will fail because the printed address will not be hashed

> > > and the buffer will contain '(ptrval)' instead.

> > > This patch adds a call to wait_for_random_bytes() before plain 'p' tests

> > > to make sure the crng is initialized.

> > 

> > Hmm, my system did not boot with this patch and

> > CONFIG_TEST_PRINTF=y

> > 

> > I guess that there was not enough entropy. It is basically a deadlock.

> > The build-in module init calls are called when SMP is enabled but

> > there is no real activity and the init calls are called sequentially.

> > Therefore there is nothing that could produce some entropy, ...

> > 

> > I suggest to skip the test when crng is not ready.

> 

> Thanks for pointing this out.

> 

> The issue is that the crng_ready() is not available outside of random.c.

> I'll leave the call to wait_for_random_bytes() if test_printf is compiled as

> a module and use add_random_ready_callback() to check if crng is initialized

> otherwise. Does that sound ok to you?


Great, I was not aware of add_random_ready_callback().

I suggest to make the decision in test_printf_init()
and run all tests either as the callback or immediately.

Best Regards,
Petr
Thierry Escande June 8, 2018, 9:07 a.m. | #5
On 08/06/2018 10:04, Petr Mladek wrote:
> On Thu 2018-06-07 20:47:25, Thierry Escande wrote:

>> Hi Petr,

>>

>> On 07/06/2018 14:24, Petr Mladek wrote:

>>> On Mon 2018-06-04 13:37:08, Thierry Escande wrote:

>>>> If the test_printf module is loaded before the crng is initialized, the

>>>> plain 'p' tests will fail because the printed address will not be hashed

>>>> and the buffer will contain '(ptrval)' instead.

>>>> This patch adds a call to wait_for_random_bytes() before plain 'p' tests

>>>> to make sure the crng is initialized.

>>>

>>> Hmm, my system did not boot with this patch and

>>> CONFIG_TEST_PRINTF=y

>>>

>>> I guess that there was not enough entropy. It is basically a deadlock.

>>> The build-in module init calls are called when SMP is enabled but

>>> there is no real activity and the init calls are called sequentially.

>>> Therefore there is nothing that could produce some entropy, ...

>>>

>>> I suggest to skip the test when crng is not ready.

>>

>> Thanks for pointing this out.

>>

>> The issue is that the crng_ready() is not available outside of random.c.

>> I'll leave the call to wait_for_random_bytes() if test_printf is compiled as

>> a module and use add_random_ready_callback() to check if crng is initialized

>> otherwise. Does that sound ok to you?

> 

> Great, I was not aware of add_random_ready_callback().

> 

> I suggest to make the decision in test_printf_init()

> and run all tests either as the callback or immediately.

> 


The run_kselftest.sh script relies on the error code returned by 
modprobe to check if the test is passed or not. So the init function has 
to return the test results and we cannot defer the test execution in the 
random ready callback if the crng is not yet initialized at __init.

My idea was to use add_random_ready_callback() as a non blocking test 
when compiled built-in as it returns -EALREADY if crng is already 
initialized.

But as I type I realize it's not necessary. I will simply enclose the 
call to wait_for_random_bytes() by #if IS_MODULE() #endif so it gets 
called only if built as a module, which is how run_kselftest.sh wants 
it... If test_printf is compiled built-in and the crng is not yet 
initialized the test will fail anyway so there is no need to add an 
extra check.

Regards,
Thierry
Andy Shevchenko June 8, 2018, 9:46 a.m. | #6
On Fri, Jun 8, 2018 at 12:07 PM, Thierry Escande
<thierry.escande@linaro.org> wrote:

> But as I type I realize it's not necessary. I will simply enclose the call

> to wait_for_random_bytes() by #if IS_MODULE() #endif so it gets called only

> if built as a module, which is how run_kselftest.sh wants it... If

> test_printf is compiled built-in and the crng is not yet initialized the

> test will fail anyway so there is no need to add an extra check.


Unfortunately I can't support this as is.
We have environments where crng will be ready minutes after the boot.
It's unacceptable.

So, we need to have means to not delay test for so long.

-- 
With Best Regards,
Andy Shevchenko
Thierry Escande June 8, 2018, 10:32 a.m. | #7
On 08/06/2018 11:46, Andy Shevchenko wrote:
> On Fri, Jun 8, 2018 at 12:07 PM, Thierry Escande

> <thierry.escande@linaro.org> wrote:

> 

>> But as I type I realize it's not necessary. I will simply enclose the call

>> to wait_for_random_bytes() by #if IS_MODULE() #endif so it gets called only

>> if built as a module, which is how run_kselftest.sh wants it... If

>> test_printf is compiled built-in and the crng is not yet initialized the

>> test will fail anyway so there is no need to add an extra check.

> 

> Unfortunately I can't support this as is.

> We have environments where crng will be ready minutes after the boot.

> It's unacceptable.

> 

> So, we need to have means to not delay test for so long.


I agree we can't delay test execution for too long. In my case the crng 
is ready only a few seconds after the boot. So we may just skip this 
plain 'p' printf test if crng is not ready then.

Regards,
Thierry
Petr Mladek June 8, 2018, 11:22 a.m. | #8
On Fri 2018-06-08 12:32:33, Thierry Escande wrote:
> On 08/06/2018 11:46, Andy Shevchenko wrote:

> > On Fri, Jun 8, 2018 at 12:07 PM, Thierry Escande

> > <thierry.escande@linaro.org> wrote:

> > 

> > > But as I type I realize it's not necessary. I will simply enclose the call

> > > to wait_for_random_bytes() by #if IS_MODULE() #endif so it gets called only

> > > if built as a module, which is how run_kselftest.sh wants it... If

> > > test_printf is compiled built-in and the crng is not yet initialized the

> > > test will fail anyway so there is no need to add an extra check.

> > 

> > Unfortunately I can't support this as is.

> > We have environments where crng will be ready minutes after the boot.

> > It's unacceptable.

> > 

> > So, we need to have means to not delay test for so long.

> 

> I agree we can't delay test execution for too long. In my case the crng is

> ready only a few seconds after the boot. So we may just skip this plain 'p'

> printf test if crng is not ready then.


Alternative solution would be to accept
const char *str = sizeof(ptr) == 8 ? "(____ptrval____)" : "(ptrval)";
as a valid result. It would make sense to print some warning in that case.

In each case, it would look ugly to use add_random_ready_callback()
wihtout passing a callback. If you really needed to check crng_ready(),
it would be better to make it public.

Best Regards,
Petr
Thierry Escande June 8, 2018, 11:28 a.m. | #9
On 08/06/2018 13:22, Petr Mladek wrote:
> On Fri 2018-06-08 12:32:33, Thierry Escande wrote:

>> On 08/06/2018 11:46, Andy Shevchenko wrote:

>>> On Fri, Jun 8, 2018 at 12:07 PM, Thierry Escande

>>> <thierry.escande@linaro.org> wrote:

>>>

>>>> But as I type I realize it's not necessary. I will simply enclose the call

>>>> to wait_for_random_bytes() by #if IS_MODULE() #endif so it gets called only

>>>> if built as a module, which is how run_kselftest.sh wants it... If

>>>> test_printf is compiled built-in and the crng is not yet initialized the

>>>> test will fail anyway so there is no need to add an extra check.

>>>

>>> Unfortunately I can't support this as is.

>>> We have environments where crng will be ready minutes after the boot.

>>> It's unacceptable.

>>>

>>> So, we need to have means to not delay test for so long.

>>

>> I agree we can't delay test execution for too long. In my case the crng is

>> ready only a few seconds after the boot. So we may just skip this plain 'p'

>> printf test if crng is not ready then.

> 

> Alternative solution would be to accept

> const char *str = sizeof(ptr) == 8 ? "(____ptrval____)" : "(ptrval)";

> as a valid result. It would make sense to print some warning in that case.

> 

> In each case, it would look ugly to use add_random_ready_callback()

> wihtout passing a callback. If you really needed to check crng_ready(),

> it would be better to make it public.


Agree but even with crng_ready() public we would have to block the test 
until it's ready which is not good either.

Accepting "(ptrval)" as a valid result seems the least bad alternative...

Regards,
Thierry
Steven Rostedt June 22, 2018, 8:53 p.m. | #10
On Thu, Jun 07, 2018 at 02:24:34PM +0200, Petr Mladek wrote:
> On Mon 2018-06-04 13:37:08, Thierry Escande wrote:

> > If the test_printf module is loaded before the crng is initialized, the

> > plain 'p' tests will fail because the printed address will not be hashed

> > and the buffer will contain '(ptrval)' instead.

> > This patch adds a call to wait_for_random_bytes() before plain 'p' tests

> > to make sure the crng is initialized.

> 

> Hmm, my system did not boot with this patch and

> CONFIG_TEST_PRINTF=y


And neither does my test box. It killed my tests I was running, as one of the
configs I test has this set.

It appears that Andrew pulled it in and sent it to Linus, as it is in
4.18-rc1, and I need to now revert this patch to make my tests work.

-- Steve


> 

> I guess that there was not enough entropy. It is basically a deadlock.

> The build-in module init calls are called when SMP is enabled but

> there is no real activity and the init calls are called sequentially.

> Therefore there is nothing that could produce some entropy, ...

> 

> I suggest to skip the test when crng is not ready.

> 

> Best Regards,

> Petr

> 

> > Signed-off-by: Thierry Escande <thierry.escande@linaro.org>

> > Acked-by: Tobin C. Harding <me@tobin.cc>

> > ---

> >  lib/test_printf.c | 7 +++++++

> >  1 file changed, 7 insertions(+)

> > 

> > diff --git a/lib/test_printf.c b/lib/test_printf.c

> > index 71ebfa43ad05..839be9385a8a 100644

> > --- a/lib/test_printf.c

> > +++ b/lib/test_printf.c

> > @@ -260,6 +260,13 @@ plain(void)

> >  {

> >  	int err;

> >  

> > +	/*

> > +	 * Make sure crng is ready. Otherwise we get "(ptrval)" instead

> > +	 * of a hashed address when printing '%p' in plain_hash() and

> > +	 * plain_format().

> > +	 */

> > +	wait_for_random_bytes();

> > +

> >  	err = plain_hash();

> >  	if (err) {

> >  		pr_warn("plain 'p' does not appear to be hashed\n");

> > -- 

> > 2.14.1

> >
Thierry Escande June 22, 2018, 9:50 p.m. | #11
On 22/06/2018 22:53, Steven Rostedt wrote:
> On Thu, Jun 07, 2018 at 02:24:34PM +0200, Petr Mladek wrote:

>> On Mon 2018-06-04 13:37:08, Thierry Escande wrote:

>>> If the test_printf module is loaded before the crng is initialized, the

>>> plain 'p' tests will fail because the printed address will not be hashed

>>> and the buffer will contain '(ptrval)' instead.

>>> This patch adds a call to wait_for_random_bytes() before plain 'p' tests

>>> to make sure the crng is initialized.

>>

>> Hmm, my system did not boot with this patch and

>> CONFIG_TEST_PRINTF=y

> 

> And neither does my test box. It killed my tests I was running, as one of the

> configs I test has this set.

> 

> It appears that Andrew pulled it in and sent it to Linus, as it is in

> 4.18-rc1, and I need to now revert this patch to make my tests work.


This patch has been superseded with a v2 and a v3 pushed into Petr 
printk.git tree 
(https://git.kernel.org/pub/scm/linux/kernel/git/pmladek/printk.git/commit/?h=for-4.19&id=ce041c43f22298485122bab15c14d062383fbc67). 
Sorry for the mess...

Regards,
Thierry

> 

> -- Steve

> 

> 

>>

>> I guess that there was not enough entropy. It is basically a deadlock.

>> The build-in module init calls are called when SMP is enabled but

>> there is no real activity and the init calls are called sequentially.

>> Therefore there is nothing that could produce some entropy, ...

>>

>> I suggest to skip the test when crng is not ready.

>>

>> Best Regards,

>> Petr

>>

>>> Signed-off-by: Thierry Escande <thierry.escande@linaro.org>

>>> Acked-by: Tobin C. Harding <me@tobin.cc>

>>> ---

>>>   lib/test_printf.c | 7 +++++++

>>>   1 file changed, 7 insertions(+)

>>>

>>> diff --git a/lib/test_printf.c b/lib/test_printf.c

>>> index 71ebfa43ad05..839be9385a8a 100644

>>> --- a/lib/test_printf.c

>>> +++ b/lib/test_printf.c

>>> @@ -260,6 +260,13 @@ plain(void)

>>>   {

>>>   	int err;

>>>   

>>> +	/*

>>> +	 * Make sure crng is ready. Otherwise we get "(ptrval)" instead

>>> +	 * of a hashed address when printing '%p' in plain_hash() and

>>> +	 * plain_format().

>>> +	 */

>>> +	wait_for_random_bytes();

>>> +

>>>   	err = plain_hash();

>>>   	if (err) {

>>>   		pr_warn("plain 'p' does not appear to be hashed\n");

>>> -- 

>>> 2.14.1

>>>
Petr Mladek June 25, 2018, 7:50 a.m. | #12
On Fri 2018-06-22 23:50:20, Thierry Escande wrote:
> On 22/06/2018 22:53, Steven Rostedt wrote:

> > On Thu, Jun 07, 2018 at 02:24:34PM +0200, Petr Mladek wrote:

> > > On Mon 2018-06-04 13:37:08, Thierry Escande wrote:

> > > > If the test_printf module is loaded before the crng is initialized, the

> > > > plain 'p' tests will fail because the printed address will not be hashed

> > > > and the buffer will contain '(ptrval)' instead.

> > > > This patch adds a call to wait_for_random_bytes() before plain 'p' tests

> > > > to make sure the crng is initialized.

> > > 

> > > Hmm, my system did not boot with this patch and

> > > CONFIG_TEST_PRINTF=y

> > 

> > And neither does my test box. It killed my tests I was running, as one of the

> > configs I test has this set.

> > 

> > It appears that Andrew pulled it in and sent it to Linus, as it is in

> > 4.18-rc1, and I need to now revert this patch to make my tests work.

> 

> This patch has been superseded with a v2 and a v3 pushed into Petr

> printk.git tree (https://git.kernel.org/pub/scm/linux/kernel/git/pmladek/printk.git/commit/?h=for-4.19&id=ce041c43f22298485122bab15c14d062383fbc67).

> Sorry for the mess...


Andrew,

should I send the revert and the better fix to Linus or would you like
to do so?

Best Regards,
Petr

Patch

diff --git a/lib/test_printf.c b/lib/test_printf.c
index 71ebfa43ad05..839be9385a8a 100644
--- a/lib/test_printf.c
+++ b/lib/test_printf.c
@@ -260,6 +260,13 @@  plain(void)
 {
 	int err;
 
+	/*
+	 * Make sure crng is ready. Otherwise we get "(ptrval)" instead
+	 * of a hashed address when printing '%p' in plain_hash() and
+	 * plain_format().
+	 */
+	wait_for_random_bytes();
+
 	err = plain_hash();
 	if (err) {
 		pr_warn("plain 'p' does not appear to be hashed\n");