2020-06-23 14:15:38

by Christian Borntraeger

[permalink] [raw]
Subject: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

Jens Markwardt reported a regression in the linux-next runs. with "umh: fix
processed error when UMH_WAIT_PROC is used" (from linux-next) a linux bridge
with an KVM guests no longer activates :

without patch
# ip addr show dev virbr1
6: virbr1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
link/ether 52:54:00:1e:3f:c0 brd ff:ff:ff:ff:ff:ff
inet 192.168.254.254/24 brd 192.168.254.255 scope global virbr1
valid_lft forever preferred_lft forever

with this patch the bridge stays DOWN with NO-CARRIER

# ip addr show dev virbr1
6: virbr1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state DOWN group default qlen 1000
link/ether 52:54:00:1e:3f:c0 brd ff:ff:ff:ff:ff:ff
inet 192.168.254.254/24 brd 192.168.254.255 scope global virbr1
valid_lft forever preferred_lft forever

This was bisected in linux-next. Reverting from linux-next also fixes the issue.

Any idea?

Christian


2020-06-24 12:06:48

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Wed, Jun 24, 2020 at 01:11:54PM +0200, Christian Borntraeger wrote:
>
>
> On 23.06.20 16:23, Christian Borntraeger wrote:
> >
> >
> > On 23.06.20 16:11, Christian Borntraeger wrote:
> >> Jens Markwardt reported a regression in the linux-next runs. with "umh: fix
> >> processed error when UMH_WAIT_PROC is used" (from linux-next) a linux bridge
> >> with an KVM guests no longer activates :
> >>
> >> without patch
> >> # ip addr show dev virbr1
> >> 6: virbr1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
> >> link/ether 52:54:00:1e:3f:c0 brd ff:ff:ff:ff:ff:ff
> >> inet 192.168.254.254/24 brd 192.168.254.255 scope global virbr1
> >> valid_lft forever preferred_lft forever
> >>
> >> with this patch the bridge stays DOWN with NO-CARRIER
> >>
> >> # ip addr show dev virbr1
> >> 6: virbr1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state DOWN group default qlen 1000
> >> link/ether 52:54:00:1e:3f:c0 brd ff:ff:ff:ff:ff:ff
> >> inet 192.168.254.254/24 brd 192.168.254.255 scope global virbr1
> >> valid_lft forever preferred_lft forever
> >>
> >> This was bisected in linux-next. Reverting from linux-next also fixes the issue.
> >>
> >> Any idea?
> >
> > FWIW, s390 is big endian. Maybe some of the shifts inn the __KW* macros are wrong.
>
> Does anyone have an idea why "umh: fix processed error when UMH_WAIT_PROC is used" breaks the
> linux-bridge on s390?

glibc for instance defines __WEXITSTATUS in only one location: bits/waitstatus.h
and it does not special case it per architecture, so at this point I'd
have to say we have to look somewhere else for why this is happening.

The commmit which caused this is issuing a correct error code down the
pipeline, nothing more. I'll make taking a look at this a priority right
now. Let us see what I come up with today.

Luis

2020-06-24 14:44:45

by Christoph Hellwig

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Wed, Jun 24, 2020 at 01:11:54PM +0200, Christian Borntraeger wrote:
> Does anyone have an idea why "umh: fix processed error when UMH_WAIT_PROC is used" breaks the
> linux-bridge on s390?

Are we even sure this is s390 specific and doesn't happen on other
architectures with the same bridge setup?

2020-06-24 15:57:26

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 24.06.20 16:43, Christoph Hellwig wrote:
> On Wed, Jun 24, 2020 at 01:11:54PM +0200, Christian Borntraeger wrote:
>> Does anyone have an idea why "umh: fix processed error when UMH_WAIT_PROC is used" breaks the
>> linux-bridge on s390?
>
> Are we even sure this is s390 specific and doesn't happen on other
> architectures with the same bridge setup?

Fair point. AFAIK nobody has tested this yet on x86.

2020-06-24 16:14:32

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Wed, Jun 24, 2020 at 01:17:25PM +0000, Luis Chamberlain wrote:
> I found however an LTP bug indicating the need to test for
> s390 wait macros [0] in light of a recent bug in glibc for s390.
> I am asking for references to that issue given I cannot find
> any mention of this on glibc yet.
>
> [0] https://github.com/linux-test-project/ltp/issues/605

I looked into this and the bug associated was:

https://sourceware.org/bugzilla/show_bug.cgi?id=19613

The commit in question was upstream glibc commit
b49ab5f4503f36dcbf43f821f817da66b2931fe6 ("Remove union wait [BZ
#19613]"), and while I don't see anything s390 mentioned there,
the issue there was due to the caller of the wait using a long
instead of an int for the return value.

In other words, that'd not the droid we are looking for.

So the issue is something else.

Luis

2020-06-24 18:16:39

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 24.06.20 19:58, Christian Borntraeger wrote:
>
>
> On 24.06.20 18:09, Luis Chamberlain wrote:
>> On Wed, Jun 24, 2020 at 05:54:46PM +0200, Christian Borntraeger wrote:
>>>
>>>
>>> On 24.06.20 16:43, Christoph Hellwig wrote:
>>>> On Wed, Jun 24, 2020 at 01:11:54PM +0200, Christian Borntraeger wrote:
>>>>> Does anyone have an idea why "umh: fix processed error when UMH_WAIT_PROC is used" breaks the
>>>>> linux-bridge on s390?
>>>>
>>>> Are we even sure this is s390 specific and doesn't happen on other
>>>> architectures with the same bridge setup?
>>>
>>> Fair point. AFAIK nobody has tested this yet on x86.
>>
>> Regardless, can you enable dynamic debug prints, to see if the kernel
>> reveals anything on the bridge code which may be relevant:
>>
>> echo "file net/bridge/* +p" > /sys/kernel/debug/dynamic_debug/control
>>
>> Luis
>
> When I start a guest the following happens with the patch:
>
> [ 47.420237] virbr0: port 2(vnet0) entered blocking state
> [ 47.420242] virbr0: port 2(vnet0) entered disabled state
> [ 47.420315] device vnet0 entered promiscuous mode
> [ 47.420365] virbr0: port 2(vnet0) event 16
> [ 47.420366] virbr0: br_fill_info event 16 port vnet0 master virbr0
> [ 47.420373] virbr0: toggle option: 12 state: 0 -> 0
> [ 47.420536] virbr0: port 2(vnet0) entered blocking state
> [ 47.420538] virbr0: port 2(vnet0) event 16
> [ 47.420539] virbr0: br_fill_info event 16 port vnet0 master virbr0
>
> and the nothing happens.
>
>
> without the patch
> [ 33.805410] virbr0: hello timer expired
> [ 35.805413] virbr0: hello timer expired
> [ 36.184349] virbr0: port 2(vnet0) entered blocking state
> [ 36.184353] virbr0: port 2(vnet0) entered disabled state
> [ 36.184427] device vnet0 entered promiscuous mode
> [ 36.184479] virbr0: port 2(vnet0) event 16
> [ 36.184480] virbr0: br_fill_info event 16 port vnet0 master virbr0
> [ 36.184487] virbr0: toggle option: 12 state: 0 -> 0
> [ 36.184636] virbr0: port 2(vnet0) entered blocking state
> [ 36.184638] virbr0: port 2(vnet0) entered listening state
> [ 36.184639] virbr0: port 2(vnet0) event 16
> [ 36.184640] virbr0: br_fill_info event 16 port vnet0 master virbr0
> [ 36.184645] virbr0: port 2(vnet0) event 16
> [ 36.184646] virbr0: br_fill_info event 16 port vnet0 master virbr0
> [ 37.805478] virbr0: hello timer expired
> [ 38.205413] virbr0: port 2(vnet0) forward delay timer
> [ 38.205414] virbr0: port 2(vnet0) entered learning state
> [ 38.205427] virbr0: port 2(vnet0) event 16
> [ 38.205430] virbr0: br_fill_info event 16 port vnet0 master virbr0
> [ 38.765414] virbr0: port 2(vnet0) hold timer expired
> [ 39.805415] virbr0: hello timer expired
> [ 40.285410] virbr0: port 2(vnet0) forward delay timer
> [ 40.285411] virbr0: port 2(vnet0) entered forwarding state
> [ 40.285418] virbr0: topology change detected, propagating
> [ 40.285420] virbr0: decreasing ageing time to 400
> [ 40.285427] virbr0: port 2(vnet0) event 16
> [ 40.285432] virbr0: br_fill_info event 16 port vnet0 master virbr0
> [ 40.765408] virbr0: port 2(vnet0) hold timer expired
> [ 41.805415] virbr0: hello timer expired
> [ 42.765426] virbr0: port 2(vnet0) hold timer expired
> [ 43.805425] virbr0: hello timer expired
> [ 44.765426] virbr0: port 2(vnet0) hold timer expired
> [ 45.805418] virbr0: hello timer expired
>
> and continuing....

Just reverting the umh.c parts like this makes the problem go away.

diff --git a/kernel/umh.c b/kernel/umh.c
index f81e8698e36e..79f139a7ca03 100644
--- a/kernel/umh.c
+++ b/kernel/umh.c
@@ -154,8 +154,8 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
* the real error code is already in sub_info->retval or
* sub_info->retval is 0 anyway, so don't mess with it then.
*/
- if (KWIFEXITED(ret))
- sub_info->retval = KWEXITSTATUS(ret);
+ if (ret)
+ sub_info->retval = ret;
}

/* Restore default kernel sig handler */


2020-06-24 18:34:03

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 24.06.20 20:09, Christian Borntraeger wrote:
>
>
> On 24.06.20 19:58, Christian Borntraeger wrote:
>>
>>
>> On 24.06.20 18:09, Luis Chamberlain wrote:
>>> On Wed, Jun 24, 2020 at 05:54:46PM +0200, Christian Borntraeger wrote:
>>>>
>>>>
>>>> On 24.06.20 16:43, Christoph Hellwig wrote:
>>>>> On Wed, Jun 24, 2020 at 01:11:54PM +0200, Christian Borntraeger wrote:
>>>>>> Does anyone have an idea why "umh: fix processed error when UMH_WAIT_PROC is used" breaks the
>>>>>> linux-bridge on s390?
>>>>>
>>>>> Are we even sure this is s390 specific and doesn't happen on other
>>>>> architectures with the same bridge setup?
>>>>
>>>> Fair point. AFAIK nobody has tested this yet on x86.
>>>
>>> Regardless, can you enable dynamic debug prints, to see if the kernel
>>> reveals anything on the bridge code which may be relevant:
>>>
>>> echo "file net/bridge/* +p" > /sys/kernel/debug/dynamic_debug/control
>>>
>>> Luis
>>
>> When I start a guest the following happens with the patch:
>>
>> [ 47.420237] virbr0: port 2(vnet0) entered blocking state
>> [ 47.420242] virbr0: port 2(vnet0) entered disabled state
>> [ 47.420315] device vnet0 entered promiscuous mode
>> [ 47.420365] virbr0: port 2(vnet0) event 16
>> [ 47.420366] virbr0: br_fill_info event 16 port vnet0 master virbr0
>> [ 47.420373] virbr0: toggle option: 12 state: 0 -> 0
>> [ 47.420536] virbr0: port 2(vnet0) entered blocking state
>> [ 47.420538] virbr0: port 2(vnet0) event 16
>> [ 47.420539] virbr0: br_fill_info event 16 port vnet0 master virbr0
>>
>> and the nothing happens.
>>
>>
>> without the patch
>> [ 33.805410] virbr0: hello timer expired
>> [ 35.805413] virbr0: hello timer expired
>> [ 36.184349] virbr0: port 2(vnet0) entered blocking state
>> [ 36.184353] virbr0: port 2(vnet0) entered disabled state
>> [ 36.184427] device vnet0 entered promiscuous mode
>> [ 36.184479] virbr0: port 2(vnet0) event 16
>> [ 36.184480] virbr0: br_fill_info event 16 port vnet0 master virbr0
>> [ 36.184487] virbr0: toggle option: 12 state: 0 -> 0
>> [ 36.184636] virbr0: port 2(vnet0) entered blocking state
>> [ 36.184638] virbr0: port 2(vnet0) entered listening state
>> [ 36.184639] virbr0: port 2(vnet0) event 16
>> [ 36.184640] virbr0: br_fill_info event 16 port vnet0 master virbr0
>> [ 36.184645] virbr0: port 2(vnet0) event 16
>> [ 36.184646] virbr0: br_fill_info event 16 port vnet0 master virbr0
>> [ 37.805478] virbr0: hello timer expired
>> [ 38.205413] virbr0: port 2(vnet0) forward delay timer
>> [ 38.205414] virbr0: port 2(vnet0) entered learning state
>> [ 38.205427] virbr0: port 2(vnet0) event 16
>> [ 38.205430] virbr0: br_fill_info event 16 port vnet0 master virbr0
>> [ 38.765414] virbr0: port 2(vnet0) hold timer expired
>> [ 39.805415] virbr0: hello timer expired
>> [ 40.285410] virbr0: port 2(vnet0) forward delay timer
>> [ 40.285411] virbr0: port 2(vnet0) entered forwarding state
>> [ 40.285418] virbr0: topology change detected, propagating
>> [ 40.285420] virbr0: decreasing ageing time to 400
>> [ 40.285427] virbr0: port 2(vnet0) event 16
>> [ 40.285432] virbr0: br_fill_info event 16 port vnet0 master virbr0
>> [ 40.765408] virbr0: port 2(vnet0) hold timer expired
>> [ 41.805415] virbr0: hello timer expired
>> [ 42.765426] virbr0: port 2(vnet0) hold timer expired
>> [ 43.805425] virbr0: hello timer expired
>> [ 44.765426] virbr0: port 2(vnet0) hold timer expired
>> [ 45.805418] virbr0: hello timer expired
>>
>> and continuing....
>
> Just reverting the umh.c parts like this makes the problem go away.
>
> diff --git a/kernel/umh.c b/kernel/umh.c
> index f81e8698e36e..79f139a7ca03 100644
> --- a/kernel/umh.c
> +++ b/kernel/umh.c
> @@ -154,8 +154,8 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> * the real error code is already in sub_info->retval or
> * sub_info->retval is 0 anyway, so don't mess with it then.
> */
> - if (KWIFEXITED(ret))
> - sub_info->retval = KWEXITSTATUS(ret);
> + if (ret)
> + sub_info->retval = ret;
> }
>
> /* Restore default kernel sig handler */

I instrumented this:

[ 5.118528] ret=0x100 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x1
[ 9.409235] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 10.114914] ret=0x100 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x1
[ 10.116308] ret=0x100 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x1
[ 10.117690] ret=0x100 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x1
[ 10.118732] ret=0x100 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x1
[ 10.119899] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 10.121365] ret=0x100 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x1
[ 10.128044] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 10.945814] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 10.962799] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 10.983755] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 10.992705] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.118877] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.124359] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.129364] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.142139] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.148385] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.153686] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.158861] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.164068] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.192445] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.200605] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.208493] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.216612] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.226467] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.525363] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.532758] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.535279] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.697660] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.701634] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.818652] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 11.836228] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 12.082266] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0
[ 40.965898] ret=0x0 KWIFEXITED(ret) = 0x1 KWEXITSTATUS(ret)= 0x0

So the translations look correct. But your change is actually a sematic change
if(ret) will only trigger if there is an error
if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
and we did not do it before.

2020-06-26 04:48:47

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
>
>
> On 24.06.20 20:32, Christian Borntraeger wrote:
> [...]>
> > So the translations look correct. But your change is actually a sematic change
> > if(ret) will only trigger if there is an error
> > if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
> > and we did not do it before.
> >
>
> So the right fix is
>
> diff --git a/kernel/umh.c b/kernel/umh.c
> index f81e8698e36e..a3a3196e84d1 100644
> --- a/kernel/umh.c
> +++ b/kernel/umh.c
> @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> * the real error code is already in sub_info->retval or
> * sub_info->retval is 0 anyway, so don't mess with it then.
> */
> - if (KWIFEXITED(ret))
> + if (KWEXITSTATUS(ret))
> sub_info->retval = KWEXITSTATUS(ret);
> }
>
> I think.

Nope, the right form is to check for WIFEXITED() before using WEXITSTATUS().
I'm not able to reproduce this on x86 with a bridge. What type of bridge
are you using on a guest, or did you mean using KVM so that the *host*
can spawn kvm guests?

It would be good if you can try to add a bridge manually and see where
things fail. Can you do something like this:

brctl addbr br0
brctl addif br0 ens6
ip link set dev br0 up

Note that most callers are for modprobe. I'd be curious to see which
umh is failing which breaks bridge for you. Can you trut this so we can
see which umh call is failing?

diff --git a/kernel/umh.c b/kernel/umh.c
index f81e8698e36e..5ad74bc301d8 100644
--- a/kernel/umh.c
+++ b/kernel/umh.c
@@ -2,6 +2,9 @@
/*
* umh - the kernel usermode helper
*/
+
+#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
+
#include <linux/module.h>
#include <linux/sched.h>
#include <linux/sched/task.h>
@@ -154,8 +157,12 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
* the real error code is already in sub_info->retval or
* sub_info->retval is 0 anyway, so don't mess with it then.
*/
- if (KWIFEXITED(ret))
+ printk("== ret: %02x\n", ret);
+ printk("== KWIFEXITED(ret): %02x\n", KWIFEXITED(ret));
+ if (KWIFEXITED(ret)) {
+ printk("KWEXITSTATUS(ret): %d\n", KWEXITSTATUS(ret));
sub_info->retval = KWEXITSTATUS(ret);
+ }
}

/* Restore default kernel sig handler */
@@ -383,6 +390,7 @@ struct subprocess_info *call_usermodehelper_setup(const char *path, char **argv,
void *data)
{
struct subprocess_info *sub_info;
+ unsigned int i = 0;
sub_info = kzalloc(sizeof(struct subprocess_info), gfp_mask);
if (!sub_info)
goto out;
@@ -394,6 +402,11 @@ struct subprocess_info *call_usermodehelper_setup(const char *path, char **argv,
#else
sub_info->path = path;
#endif
+ pr_info("sub_info->path: %s\n", sub_info->path);
+ while (argv[i])
+ printk(KERN_INFO "%s ", argv[i++]);
+ printk(KERN_INFO "\n");
+
sub_info->argv = argv;
sub_info->envp = envp;


2020-06-26 05:24:59

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 26.06.20 04:54, Luis Chamberlain wrote:
> On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
>>
>>
>> On 24.06.20 20:32, Christian Borntraeger wrote:
>> [...]>
>>> So the translations look correct. But your change is actually a sematic change
>>> if(ret) will only trigger if there is an error
>>> if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
>>> and we did not do it before.
>>>
>>
>> So the right fix is
>>
>> diff --git a/kernel/umh.c b/kernel/umh.c
>> index f81e8698e36e..a3a3196e84d1 100644
>> --- a/kernel/umh.c
>> +++ b/kernel/umh.c
>> @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
>> * the real error code is already in sub_info->retval or
>> * sub_info->retval is 0 anyway, so don't mess with it then.
>> */
>> - if (KWIFEXITED(ret))
>> + if (KWEXITSTATUS(ret))
>> sub_info->retval = KWEXITSTATUS(ret);
>> }
>>
>> I think.
>
> Nope, the right form is to check for WIFEXITED() before using WEXITSTATUS().

But this IS a change over the previous code, no?
I will test next week as I am travelling right now.

2020-06-26 09:01:57

by Christoph Hellwig

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Fri, Jun 26, 2020 at 07:22:34AM +0200, Christian Borntraeger wrote:
>
>
> On 26.06.20 04:54, Luis Chamberlain wrote:
> > On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
> >>
> >>
> >> On 24.06.20 20:32, Christian Borntraeger wrote:
> >> [...]>
> >>> So the translations look correct. But your change is actually a sematic change
> >>> if(ret) will only trigger if there is an error
> >>> if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
> >>> and we did not do it before.
> >>>
> >>
> >> So the right fix is
> >>
> >> diff --git a/kernel/umh.c b/kernel/umh.c
> >> index f81e8698e36e..a3a3196e84d1 100644
> >> --- a/kernel/umh.c
> >> +++ b/kernel/umh.c
> >> @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> >> * the real error code is already in sub_info->retval or
> >> * sub_info->retval is 0 anyway, so don't mess with it then.
> >> */
> >> - if (KWIFEXITED(ret))
> >> + if (KWEXITSTATUS(ret))
> >> sub_info->retval = KWEXITSTATUS(ret);
> >> }
> >>
> >> I think.
> >
> > Nope, the right form is to check for WIFEXITED() before using WEXITSTATUS().
>
> But this IS a change over the previous code, no?
> I will test next week as I am travelling right now.

I'm all for reverting back to the previous behavior. If someone wants
a behavior change it should be a separate patch. And out of pure self
interest I'd like to see that change after my addition of the
kernel_wait helper to replace the kernel_wait4 abuse :)

2020-06-26 12:31:16

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Fri, Jun 26, 2020 at 10:00:01AM +0100, Christoph Hellwig wrote:
> On Fri, Jun 26, 2020 at 07:22:34AM +0200, Christian Borntraeger wrote:
> >
> >
> > On 26.06.20 04:54, Luis Chamberlain wrote:
> > > On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
> > >>
> > >>
> > >> On 24.06.20 20:32, Christian Borntraeger wrote:
> > >> [...]>
> > >>> So the translations look correct. But your change is actually a sematic change
> > >>> if(ret) will only trigger if there is an error
> > >>> if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
> > >>> and we did not do it before.
> > >>>
> > >>
> > >> So the right fix is
> > >>
> > >> diff --git a/kernel/umh.c b/kernel/umh.c
> > >> index f81e8698e36e..a3a3196e84d1 100644
> > >> --- a/kernel/umh.c
> > >> +++ b/kernel/umh.c
> > >> @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> > >> * the real error code is already in sub_info->retval or
> > >> * sub_info->retval is 0 anyway, so don't mess with it then.
> > >> */
> > >> - if (KWIFEXITED(ret))
> > >> + if (KWEXITSTATUS(ret))
> > >> sub_info->retval = KWEXITSTATUS(ret);
> > >> }
> > >>
> > >> I think.
> > >
> > > Nope, the right form is to check for WIFEXITED() before using WEXITSTATUS().
> >
> > But this IS a change over the previous code, no?
> > I will test next week as I am travelling right now.
>
> I'm all for reverting back to the previous behavior. If someone wants
> a behavior change it should be a separate patch. And out of pure self
> interest I'd like to see that change after my addition of the
> kernel_wait helper to replace the kernel_wait4 abuse :)

Yeah sure, this will be *slightly* cleaner after that. Today we
implicitly return -ECHLD as well under the assumption the kernel_wait4()
call failed.

Andrew, can you please revert these two for now:

selftests: simplify kmod failure value
umh: fix processed error when UMH_WAIT_PROC is used

Later, we'll add Christoph's simplier kernel wait, and make the change
directly there to catpure the right error. That still won't fix this reported
issue, but it will be cleaner and will go tested by Christian Borntraeger
before.

Luis

2020-06-26 12:37:19

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Fri, Jun 26, 2020 at 11:40:08AM +0000, Luis Chamberlain wrote:
> Andrew, can you please revert these two for now:
>
> selftests: simplify kmod failure value
> umh: fix processed error when UMH_WAIT_PROC is used
>
> Later, we'll add Christoph's simplier kernel wait, and make the change
> directly there to catpure the right error. That still won't fix this reported
> issue, but it will be cleaner and will go tested by Christian Borntraeger
> before.

However, note that the only consideration to make here against this
approach of the fix later going in with the simpler kernel wait is
if this actually is fixing a real issue, and if we'd want this going to
stable.

We should for sure revert though, so Andrew please do proceed to revert
or drop those two patches alone for now.

It was unclear to me if this should go to stable given I was not sure
how severe that NFS case mentioned on the commit log was, and no one on
the NFS side has replied about that yet, however there may be other
areas where code inspection of callsites was not sufficient to find the
real critical areas.

I'm now very curious what this issue that Christian with bridge on s390
found will be.

Luis

2020-06-30 19:18:52

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Fri, Jun 26, 2020 at 02:54:10AM +0000, Luis Chamberlain wrote:
> On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
> >
> >
> > On 24.06.20 20:32, Christian Borntraeger wrote:
> > [...]>
> > > So the translations look correct. But your change is actually a sematic change
> > > if(ret) will only trigger if there is an error
> > > if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
> > > and we did not do it before.
> > >
> >
> > So the right fix is
> >
> > diff --git a/kernel/umh.c b/kernel/umh.c
> > index f81e8698e36e..a3a3196e84d1 100644
> > --- a/kernel/umh.c
> > +++ b/kernel/umh.c
> > @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> > * the real error code is already in sub_info->retval or
> > * sub_info->retval is 0 anyway, so don't mess with it then.
> > */
> > - if (KWIFEXITED(ret))
> > + if (KWEXITSTATUS(ret))
> > sub_info->retval = KWEXITSTATUS(ret);
> > }
> >
> > I think.
>
> Nope, the right form is to check for WIFEXITED() before using WEXITSTATUS().
> I'm not able to reproduce this on x86 with a bridge. What type of bridge
> are you using on a guest, or did you mean using KVM so that the *host*
> can spawn kvm guests?
>
> It would be good if you can try to add a bridge manually and see where
> things fail. Can you do something like this:
>
> brctl addbr br0
> brctl addif br0 ens6
> ip link set dev br0 up
>
> Note that most callers are for modprobe. I'd be curious to see which
> umh is failing which breaks bridge for you. Can you trut this so we can
> see which umh call is failing?

Christian, any luck getting to test the code below to see what this
reveals?

Luis

>
> diff --git a/kernel/umh.c b/kernel/umh.c
> index f81e8698e36e..5ad74bc301d8 100644
> --- a/kernel/umh.c
> +++ b/kernel/umh.c
> @@ -2,6 +2,9 @@
> /*
> * umh - the kernel usermode helper
> */
> +
> +#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
> +
> #include <linux/module.h>
> #include <linux/sched.h>
> #include <linux/sched/task.h>
> @@ -154,8 +157,12 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> * the real error code is already in sub_info->retval or
> * sub_info->retval is 0 anyway, so don't mess with it then.
> */
> - if (KWIFEXITED(ret))
> + printk("== ret: %02x\n", ret);
> + printk("== KWIFEXITED(ret): %02x\n", KWIFEXITED(ret));
> + if (KWIFEXITED(ret)) {
> + printk("KWEXITSTATUS(ret): %d\n", KWEXITSTATUS(ret));
> sub_info->retval = KWEXITSTATUS(ret);
> + }
> }
>
> /* Restore default kernel sig handler */
> @@ -383,6 +390,7 @@ struct subprocess_info *call_usermodehelper_setup(const char *path, char **argv,
> void *data)
> {
> struct subprocess_info *sub_info;
> + unsigned int i = 0;
> sub_info = kzalloc(sizeof(struct subprocess_info), gfp_mask);
> if (!sub_info)
> goto out;
> @@ -394,6 +402,11 @@ struct subprocess_info *call_usermodehelper_setup(const char *path, char **argv,
> #else
> sub_info->path = path;
> #endif
> + pr_info("sub_info->path: %s\n", sub_info->path);
> + while (argv[i])
> + printk(KERN_INFO "%s ", argv[i++]);
> + printk(KERN_INFO "\n");
> +
> sub_info->argv = argv;
> sub_info->envp = envp;
>
>

2020-07-01 10:09:46

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 30.06.20 19:57, Luis Chamberlain wrote:
> On Fri, Jun 26, 2020 at 02:54:10AM +0000, Luis Chamberlain wrote:
>> On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
>>>
>>>
>>> On 24.06.20 20:32, Christian Borntraeger wrote:
>>> [...]>
>>>> So the translations look correct. But your change is actually a sematic change
>>>> if(ret) will only trigger if there is an error
>>>> if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
>>>> and we did not do it before.
>>>>
>>>
>>> So the right fix is
>>>
>>> diff --git a/kernel/umh.c b/kernel/umh.c
>>> index f81e8698e36e..a3a3196e84d1 100644
>>> --- a/kernel/umh.c
>>> +++ b/kernel/umh.c
>>> @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
>>> * the real error code is already in sub_info->retval or
>>> * sub_info->retval is 0 anyway, so don't mess with it then.
>>> */
>>> - if (KWIFEXITED(ret))
>>> + if (KWEXITSTATUS(ret))
>>> sub_info->retval = KWEXITSTATUS(ret);
>>> }
>>>
>>> I think.
>>
>> Nope, the right form is to check for WIFEXITED() before using WEXITSTATUS().
>> I'm not able to reproduce this on x86 with a bridge. What type of bridge
>> are you using on a guest, or did you mean using KVM so that the *host*
>> can spawn kvm guests?
>>
>> It would be good if you can try to add a bridge manually and see where
>> things fail. Can you do something like this:
>>
>> brctl addbr br0
>> brctl addif br0 ens6
>> ip link set dev br0 up
>>
>> Note that most callers are for modprobe. I'd be curious to see which
>> umh is failing which breaks bridge for you. Can you trut this so we can
>> see which umh call is failing?
>
> Christian, any luck getting to test the code below to see what this
> reveals?
>
> Luis

dmesg attached


Attachments:
dmesg.txt (40.62 kB)

2020-07-01 13:47:26

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Wed, Jul 01, 2020 at 12:08:11PM +0200, Christian Borntraeger wrote:
> dmesg attached
> [ 14.438482] virbr0: port 1(virbr0-nic) entered blocking state
> [ 14.438485] virbr0: port 1(virbr0-nic) entered disabled state
> [ 14.438635] device virbr0-nic entered promiscuous mode
> [ 14.439654] umh: sub_info->path: /sbin/bridge-stp
> [ 14.439656] /sbin/bridge-stp
> [ 14.439656] virbr0
> [ 14.439656] start

OK so what we seem to want to debug is the umh call for:

/sbin/bridge-stp virbr0 start

> [ 14.439734] == ret: 00
> [ 14.439735] == KWIFEXITED(ret): 01
> [ 14.439736] KWEXITSTATUS(ret): 0

Its not clear if this is the respective return value, but now
that we have a clue that this is the the only non-modprobe
call, we should have a clearer certainty that this is the
issue.

Indeed my patch "umh: fix processed error when UMH_WAIT_PROC is used"
did modify bridge-stp in the following way:

diff --git a/net/bridge/br_stp_if.c b/net/bridge/br_stp_if.c
index ba55851fe132..bdd94b45396b 100644
--- a/net/bridge/br_stp_if.c
+++ b/net/bridge/br_stp_if.c
@@ -133,14 +133,8 @@ static int br_stp_call_user(struct net_bridge *br, char *arg)

/* call userspace STP and report program errors */
rc = call_usermodehelper(BR_STP_PROG, argv, envp, UMH_WAIT_PROC);
- if (rc > 0) {
- if (rc & 0xff)
- br_debug(br, BR_STP_PROG " received signal %d\n",
- rc & 0x7f);
- else
- br_debug(br, BR_STP_PROG " exited with code %d\n",
- (rc >> 8) & 0xff);
- }
+ if (rc != 0)
+ br_debug(br, BR_STP_PROG " failed with exit code %d\n", rc);

return rc;
}

If you look at this carefully though you'll notice that the change just
modifies *when* we issue the debug print. The more important relevant
part of the patch however was that we now do return a correct error
value when the call fails.

More importantly, depending on if an error or not we run the kernel STP
or userspace STP later:

static void br_stp_start(struct net_bridge *br)
{
int err = -ENOENT;

if (net_eq(dev_net(br->dev), &init_net))
err = br_stp_call_user(br, "start");

if (err && err != -ENOENT)
br_err(br, "failed to start userspace STP (%d)\n", err);

spin_lock_bh(&br->lock);

if (br->bridge_forward_delay < BR_MIN_FORWARD_DELAY)
__br_set_forward_delay(br, BR_MIN_FORWARD_DELAY);
else if (br->bridge_forward_delay > BR_MAX_FORWARD_DELAY)
__br_set_forward_delay(br, BR_MAX_FORWARD_DELAY);

---------------------> can you enable debug print for this to see what
---------------------> you end up using?
if (!err) {
br->stp_enabled = BR_USER_STP;
br_debug(br, "userspace STP started\n");
} else {
br->stp_enabled = BR_KERNEL_STP;
br_debug(br, "using kernel STP\n");

/* To start timers on any ports left in blocking */
if (br->dev->flags & IFF_UP)
mod_timer(&br->hello_timer, jiffies + br->hello_time);
br_port_state_selection(br);
}
----------------->

spin_unlock_bh(&br->lock);
}

2020-07-01 13:54:18

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Wed, Jul 01, 2020 at 10:24:29PM +0900, Tetsuo Handa wrote:
> On 2020/07/01 19:08, Christian Borntraeger wrote:
> >
> >
> > On 30.06.20 19:57, Luis Chamberlain wrote:
> >> On Fri, Jun 26, 2020 at 02:54:10AM +0000, Luis Chamberlain wrote:
> >>> On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
> >>>>
> >>>>
> >>>> On 24.06.20 20:32, Christian Borntraeger wrote:
> >>>> [...]>
> >>>>> So the translations look correct. But your change is actually a sematic change
> >>>>> if(ret) will only trigger if there is an error
> >>>>> if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
> >>>>> and we did not do it before.
> >>>>>
> >>>>
> >>>> So the right fix is
> >>>>
> >>>> diff --git a/kernel/umh.c b/kernel/umh.c
> >>>> index f81e8698e36e..a3a3196e84d1 100644
> >>>> --- a/kernel/umh.c
> >>>> +++ b/kernel/umh.c
> >>>> @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> >>>> * the real error code is already in sub_info->retval or
> >>>> * sub_info->retval is 0 anyway, so don't mess with it then.
> >>>> */
> >>>> - if (KWIFEXITED(ret))
> >>>> + if (KWEXITSTATUS(ret))
> >>>> sub_info->retval = KWEXITSTATUS(ret);
>
> Well, it is not br_stp_call_user() but br_stp_start() which is expecting
> to set sub_info->retval for both KWIFEXITED() case and KWIFSIGNALED() case.
> That is, sub_info->retval needs to carry raw value (i.e. without "umh: fix
> processed error when UMH_WAIT_PROC is used" will be the correct behavior).

br_stp_start() doesn't check for the raw value, it just checks for err
or !err. So the patch, "umh: fix processed error when UMH_WAIT_PROC is
used" propagates the correct error now.

Christian, can you try removing the binary temporarily and seeing if
you get your bridge working?

Luis

2020-07-01 14:12:40

by Tetsuo Handa

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On 2020/07/01 22:53, Luis Chamberlain wrote:
>> Well, it is not br_stp_call_user() but br_stp_start() which is expecting
>> to set sub_info->retval for both KWIFEXITED() case and KWIFSIGNALED() case.
>> That is, sub_info->retval needs to carry raw value (i.e. without "umh: fix
>> processed error when UMH_WAIT_PROC is used" will be the correct behavior).
>
> br_stp_start() doesn't check for the raw value, it just checks for err
> or !err. So the patch, "umh: fix processed error when UMH_WAIT_PROC is
> used" propagates the correct error now.

No. If "/sbin/bridge-stp virbr0 start" terminated due to e.g. SIGSEGV
(for example, by inserting "kill -SEGV $$" into right after "#!/bin/sh" line),
br_stp_start() needs to select BR_KERNEL_STP path. We can't assume that
/sbin/bridge-stp is always terminated by exit() syscall (and hence we can't
ignore KWIFSIGNALED() case in call_usermodehelper_exec_sync()).

2020-07-01 15:28:01

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 01.07.20 15:53, Luis Chamberlain wrote:
> On Wed, Jul 01, 2020 at 10:24:29PM +0900, Tetsuo Handa wrote:
>> On 2020/07/01 19:08, Christian Borntraeger wrote:
>>>
>>>
>>> On 30.06.20 19:57, Luis Chamberlain wrote:
>>>> On Fri, Jun 26, 2020 at 02:54:10AM +0000, Luis Chamberlain wrote:
>>>>> On Wed, Jun 24, 2020 at 08:37:55PM +0200, Christian Borntraeger wrote:
>>>>>>
>>>>>>
>>>>>> On 24.06.20 20:32, Christian Borntraeger wrote:
>>>>>> [...]>
>>>>>>> So the translations look correct. But your change is actually a sematic change
>>>>>>> if(ret) will only trigger if there is an error
>>>>>>> if (KWIFEXITED(ret)) will always trigger when the process ends. So we will always overwrite -ECHILD
>>>>>>> and we did not do it before.
>>>>>>>
>>>>>>
>>>>>> So the right fix is
>>>>>>
>>>>>> diff --git a/kernel/umh.c b/kernel/umh.c
>>>>>> index f81e8698e36e..a3a3196e84d1 100644
>>>>>> --- a/kernel/umh.c
>>>>>> +++ b/kernel/umh.c
>>>>>> @@ -154,7 +154,7 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
>>>>>> * the real error code is already in sub_info->retval or
>>>>>> * sub_info->retval is 0 anyway, so don't mess with it then.
>>>>>> */
>>>>>> - if (KWIFEXITED(ret))
>>>>>> + if (KWEXITSTATUS(ret))
>>>>>> sub_info->retval = KWEXITSTATUS(ret);
>>
>> Well, it is not br_stp_call_user() but br_stp_start() which is expecting
>> to set sub_info->retval for both KWIFEXITED() case and KWIFSIGNALED() case.
>> That is, sub_info->retval needs to carry raw value (i.e. without "umh: fix
>> processed error when UMH_WAIT_PROC is used" will be the correct behavior).
>
> br_stp_start() doesn't check for the raw value, it just checks for err
> or !err. So the patch, "umh: fix processed error when UMH_WAIT_PROC is
> used" propagates the correct error now.
>
> Christian, can you try removing the binary temporarily and seeing if
> you get your bridge working?

As I matter of fact I do NOT have /sbin/bridge-stp installed.

2020-07-01 15:39:35

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Wed, Jul 01, 2020 at 11:08:57PM +0900, Tetsuo Handa wrote:
> On 2020/07/01 22:53, Luis Chamberlain wrote:
> >> Well, it is not br_stp_call_user() but br_stp_start() which is expecting
> >> to set sub_info->retval for both KWIFEXITED() case and KWIFSIGNALED() case.
> >> That is, sub_info->retval needs to carry raw value (i.e. without "umh: fix
> >> processed error when UMH_WAIT_PROC is used" will be the correct behavior).
> >
> > br_stp_start() doesn't check for the raw value, it just checks for err
> > or !err. So the patch, "umh: fix processed error when UMH_WAIT_PROC is
> > used" propagates the correct error now.
>
> No. If "/sbin/bridge-stp virbr0 start" terminated due to e.g. SIGSEGV
> (for example, by inserting "kill -SEGV $$" into right after "#!/bin/sh" line),
> br_stp_start() needs to select BR_KERNEL_STP path. We can't assume that
> /sbin/bridge-stp is always terminated by exit() syscall (and hence we can't
> ignore KWIFSIGNALED() case in call_usermodehelper_exec_sync()).

Ah, well that would be a different fix required, becuase again,
br_stp_start() does not untangle the correct error today really.
I also I think it would be odd odd that SIGSEGV or another signal
is what was terminating Christian's bridge stp call, but let's
find out!

Note we pass 0 to the options to wait so the mistake here could indeed
be that we did not need KWIFSIGNALED(). I was afraid of this prospect...
as it other implications.

It means we either *open code* all callers, or we handle this in a
unified way on the umh. And if we do handle this in a unified way, it
then begs the question as to *what* do we pass for the signals case and
continued case. Below we just pass the signal, and treat continued as
OK, but treating continued as OK would also be a *new* change as well.

For instance (this goes just boot tested, but Christian if you can
try this as well that would be appreciated):

diff --git a/include/linux/sched/task.h b/include/linux/sched/task.h
index bba06befbff5..d1898f5dd1fc 100644
--- a/include/linux/sched/task.h
+++ b/include/linux/sched/task.h
@@ -105,10 +105,12 @@ extern long kernel_wait4(pid_t, int __user *, int, struct rusage *);

/* Only add helpers for actual use cases in the kernel */
#define KWEXITSTATUS(status) (__KWEXITSTATUS(status))
+#define KWTERMSIG(status) (__KWTERMSIG(status))
+#define KWSTOPSIG(status) (__KWSTOPSIG(status))
#define KWIFEXITED(status) (__KWIFEXITED(status))
-
-/* Nonzero if STATUS indicates normal termination. */
-#define __KWIFEXITED(status) (__KWTERMSIG(status) == 0)
+#define KWIFSIGNALED(status) (__KWIFSIGNALED(status))
+#define KWIFSTOPPED(status) (__KWIFSTOPPED(status))
+#define KWIFCONTINUED(status) (__KWIFCONTINUED(status))

/* If KWIFEXITED(STATUS), the low-order 8 bits of the status. */
#define __KWEXITSTATUS(status) (((status) & 0xff00) >> 8)
@@ -116,6 +118,24 @@ extern long kernel_wait4(pid_t, int __user *, int, struct rusage *);
/* If KWIFSIGNALED(STATUS), the terminating signal. */
#define __KWTERMSIG(status) ((status) & 0x7f)

+/* If KWIFSTOPPED(STATUS), the signal that stopped the child. */
+#define __KWSTOPSIG(status) __KWEXITSTATUS(status)
+
+/* Nonzero if STATUS indicates normal termination. */
+#define __KWIFEXITED(status) (__KWTERMSIG(status) == 0)
+
+/* Nonzero if STATUS indicates termination by a signal. */
+#define __KWIFSIGNALED(status) \
+ (((signed char) (((status) & 0x7f) + 1) >> 1) > 0)
+
+/* Nonzero if STATUS indicates the child is stopped. */
+#define __KWIFSTOPPED(status) (((status) & 0xff) == 0x7f)
+
+/* Nonzero if STATUS indicates the child continued after a stop. */
+#define __KWIFCONTINUED(status) ((status) == __KW_CONTINUED)
+
+#define __KW_CONTINUED 0xffff
+
extern void free_task(struct task_struct *tsk);

/* sched_exec is called by processes performing an exec */
diff --git a/kernel/umh.c b/kernel/umh.c
index f81e8698e36e..c98fb1ed90c9 100644
--- a/kernel/umh.c
+++ b/kernel/umh.c
@@ -156,6 +156,18 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
*/
if (KWIFEXITED(ret))
sub_info->retval = KWEXITSTATUS(ret);
+ /*
+ * Do we really want to be passing the signal, or do we pass
+ * a single error code for all cases?
+ */
+ else if (KWIFSIGNALED(ret))
+ sub_info->retval = KWTERMSIG(ret);
+ /* Same here */
+ else if (KWIFSTOPPED((ret)))
+ sub_info->retval = KWSTOPSIG(ret);
+ /* And are we really sure we want this? */
+ else if (KWIFCONTINUED((ret)))
+ sub_info->retval = 0;
}

/* Restore default kernel sig handler */

2020-07-01 15:50:07

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 01.07.20 17:38, Luis Chamberlain wrote:
> On Wed, Jul 01, 2020 at 11:08:57PM +0900, Tetsuo Handa wrote:
>> On 2020/07/01 22:53, Luis Chamberlain wrote:
>>>> Well, it is not br_stp_call_user() but br_stp_start() which is expecting
>>>> to set sub_info->retval for both KWIFEXITED() case and KWIFSIGNALED() case.
>>>> That is, sub_info->retval needs to carry raw value (i.e. without "umh: fix
>>>> processed error when UMH_WAIT_PROC is used" will be the correct behavior).
>>>
>>> br_stp_start() doesn't check for the raw value, it just checks for err
>>> or !err. So the patch, "umh: fix processed error when UMH_WAIT_PROC is
>>> used" propagates the correct error now.
>>
>> No. If "/sbin/bridge-stp virbr0 start" terminated due to e.g. SIGSEGV
>> (for example, by inserting "kill -SEGV $$" into right after "#!/bin/sh" line),
>> br_stp_start() needs to select BR_KERNEL_STP path. We can't assume that
>> /sbin/bridge-stp is always terminated by exit() syscall (and hence we can't
>> ignore KWIFSIGNALED() case in call_usermodehelper_exec_sync()).
>
> Ah, well that would be a different fix required, becuase again,
> br_stp_start() does not untangle the correct error today really.
> I also I think it would be odd odd that SIGSEGV or another signal
> is what was terminating Christian's bridge stp call, but let's
> find out!
>
> Note we pass 0 to the options to wait so the mistake here could indeed
> be that we did not need KWIFSIGNALED(). I was afraid of this prospect...
> as it other implications.
>
> It means we either *open code* all callers, or we handle this in a
> unified way on the umh. And if we do handle this in a unified way, it
> then begs the question as to *what* do we pass for the signals case and
> continued case. Below we just pass the signal, and treat continued as
> OK, but treating continued as OK would also be a *new* change as well.
>
> For instance (this goes just boot tested, but Christian if you can
> try this as well that would be appreciated):


Does not help, the bridge stays in DOWN state.

2020-07-01 16:05:19

by Christian Borntraeger

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)



On 01.07.20 17:58, Luis Chamberlain wrote:
[...]

>>>
>>> Ah, well that would be a different fix required, becuase again,
>>> br_stp_start() does not untangle the correct error today really.
>>> I also I think it would be odd odd that SIGSEGV or another signal
>>> is what was terminating Christian's bridge stp call, but let's
>>> find out!
>>>
>>> Note we pass 0 to the options to wait so the mistake here could indeed
>>> be that we did not need KWIFSIGNALED(). I was afraid of this prospect...
>>> as it other implications.
>>>
>>> It means we either *open code* all callers, or we handle this in a
>>> unified way on the umh. And if we do handle this in a unified way, it
>>> then begs the question as to *what* do we pass for the signals case and
>>> continued case. Below we just pass the signal, and treat continued as
>>> OK, but treating continued as OK would also be a *new* change as well.
>>>
>>> For instance (this goes just boot tested, but Christian if you can
>>> try this as well that would be appreciated):
>>
>>
>> Does not help, the bridge stays in DOWN state.
>
> OK thanks for testing, that was fast! Does your code go through the
> STP kernel path or userpath? If it is taking the STP kernel path
> then this is not the real culprit to your issue then.

I have no idea and I cannot look into this right now. I can test
patches as compile,reboot and test is almost no effort.

FWIW, this is just the network of a KVM guest of libvirts default network
no longer working, maybe you can reproduce this on x86 as well?

2020-07-02 19:47:40

by Luis Chamberlain

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On Thu, Jul 02, 2020 at 01:26:53PM +0900, Tetsuo Handa wrote:
> On 2020/07/02 0:38, Luis Chamberlain wrote:
> > @@ -156,6 +156,18 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
> > */
> > if (KWIFEXITED(ret))
> > sub_info->retval = KWEXITSTATUS(ret);
> > + /*
> > + * Do we really want to be passing the signal, or do we pass
> > + * a single error code for all cases?
> > + */
> > + else if (KWIFSIGNALED(ret))
> > + sub_info->retval = KWTERMSIG(ret);
>
> No, this is bad. Caller of usermode helper is unable to distinguish exit(9)
> and e.g. SIGKILL'ed by the OOM-killer.

Right, the question is: do we care?

> Please pass raw exit status value.
>
> I feel that caller of usermode helper should not use exit status value.
> For example, call_sbin_request_key() is checking
>
> test_bit(KEY_FLAG_USER_CONSTRUCT, &key->flags) || key_validate(key) < 0
>
> condition (if usermode helper was invoked) in order to "ignore any errors from
> userspace if the key was instantiated".

For those not familiar with this code path, or if you cannot decipher
the above, the code path in question was:

static int call_sbin_request_key(struct key *authkey, void *aux)
{
...
/* do it */
ret = call_usermodehelper_keys(request_key, argv, envp, keyring,
UMH_WAIT_PROC);
kdebug("usermode -> 0x%x", ret);
if (ret >= 0) {
/* ret is the exit/wait code */
if (test_bit(KEY_FLAG_USER_CONSTRUCT, &key->flags) ||
key_validate(key) < 0)
ret = -ENOKEY;
/* ignore any errors from userspace if the key was
* instantiated */
ret = 0;
}
...
}

And the umh patch "umh: fix processed error when UMH_WAIT_PROC is used"
changed this to:

- if (ret >= 0) {
+ if (ret != 0) {

Prior to the patch negative return values from userspace were still
being captured, and likewise signals, but the error value was not
raw, not the actual value. After the patch, since we check for ret != 0
we still upkeep the sanity check for any error, correct the error value,
but as you noted signals were ignored as I made the wrong assumption
we would ignore them. The umh sub_info->retval is set after my original
patch only if KWIFSIGNALED(ret)), and ignored signals, and so that
would be now capitured with the additional KWIFSIGNALED(ret)) check.

The question still stands:

Do we want to open code all these checks or simply wrap them up in
the umh. If we do the later, as you note exit(9) and a SIGKILL will
be the same to the inspector in the kernel. But do we care?

Do we really want umh callers differntiatin between signals and exit values?

The alternative to making a compromise is using generic wrappers for
things which make sense and letting the callers use those.

Luis

> > + /* Same here */
> > + else if (KWIFSTOPPED((ret)))
> > + sub_info->retval = KWSTOPSIG(ret);
> > + /* And are we really sure we want this? */
> > + else if (KWIFCONTINUED((ret)))
> > + sub_info->retval = 0;
> > }
> >
> > /* Restore default kernel sig handler */
> >
>

2020-07-03 00:55:14

by Tetsuo Handa

[permalink] [raw]
Subject: Re: linux-next: umh: fix processed error when UMH_WAIT_PROC is used seems to break linux bridge on s390x (bisected)

On 2020/07/03 4:46, Luis Chamberlain wrote:
> On Thu, Jul 02, 2020 at 01:26:53PM +0900, Tetsuo Handa wrote:
>> On 2020/07/02 0:38, Luis Chamberlain wrote:
>>> @@ -156,6 +156,18 @@ static void call_usermodehelper_exec_sync(struct subprocess_info *sub_info)
>>> */
>>> if (KWIFEXITED(ret))
>>> sub_info->retval = KWEXITSTATUS(ret);
>>> + /*
>>> + * Do we really want to be passing the signal, or do we pass
>>> + * a single error code for all cases?
>>> + */
>>> + else if (KWIFSIGNALED(ret))
>>> + sub_info->retval = KWTERMSIG(ret);
>>
>> No, this is bad. Caller of usermode helper is unable to distinguish exit(9)
>> and e.g. SIGKILL'ed by the OOM-killer.
>
> Right, the question is: do we care?

Yes, we have to care.

> And the umh patch "umh: fix processed error when UMH_WAIT_PROC is used"
> changed this to:
>
> - if (ret >= 0) {
> + if (ret != 0) {
>
> Prior to the patch negative return values from userspace were still
> being captured, and likewise signals, but the error value was not
> raw, not the actual value. After the patch, since we check for ret != 0
> we still upkeep the sanity check for any error, correct the error value,
> but as you noted signals were ignored as I made the wrong assumption
> we would ignore them. The umh sub_info->retval is set after my original
> patch only if KWIFSIGNALED(ret)), and ignored signals, and so that
> would be now capitured with the additional KWIFSIGNALED(ret)) check.

"call_usermodehelper_keys() == 0" (i.e. usermode helper was successfully
started and successfully terminated via exit(0)) is different from "there is
nothing to do". call_sbin_request_key() == 0 case still has to check for
possibility of -ENOKEY case.

>
> The question still stands:
>
> Do we want to open code all these checks or simply wrap them up in
> the umh. If we do the later, as you note exit(9) and a SIGKILL will
> be the same to the inspector in the kernel. But do we care?

Yes, we do care.

>
> Do we really want umh callers differntiatin between signals and exit values?

Yes, we do.

>
> The alternative to making a compromise is using generic wrappers for
> things which make sense and letting the callers use those.

I suggest just introducing KWIFEXITED()/KWEXITSTATUS()/KWIFSIGNALED()/KWTERMSIG()
macros and fixing the callers, for some callers are not aware of possibility of
KWIFSIGNALED() case.

For example, conn_try_outdate_peer() in drivers/block/drbd/drbd_nl.c misbehaves if
drbd_usermode_helper process was terminated by a signal, for the switch() statement
after returning from conn_helper() is assuming that the return value of conn_helper()
is a KWEXITSTATUS() value if drbd_usermode_helper process was successfully started.
If drbd_usermode_helper process was terminated by SIGQUIT (which is 3),
conn_try_outdate_peer() will by error hit "case P_INCONSISTENT:" (which is 3);
conn_try_outdate_peer() should hit "default: /* The script is broken ... */"
unless KWIFEXITED() == true.

Your patch is trying to obnubilate the return code.