Debian Bug report logs - #628690
openssh-server inherits oom_adj -17 upon start under specific conditions, causing DoS potential for oom_killer

Reply or subscribe to this bug.

Toggle useless messages

Message #5 received at submit@bugs.debian.org (full text, mbox, reply):

From: "Cal Leeming [Simplicity Media Ltd]" <cal.leeming@simplicitymedialtd.co.uk>

To: submit@bugs.debian.org, gert@greenie.muc.de

Subject: openssh-server inherits oom_adj -17 upon start under specific conditions, causing DoS potential for oom_killer

Date: Tue, 31 May 2011 12:22:50 +0100

Package: openssh-server
Version: 1:5.5p1-6-amd64

Full discussion about this problem (including full log dumps, analysis, 
testing etc), can be found at:

http://www.debianhelp.org/content/cgroup-oom-killer-loop-causes-system-lockup-possible-fix-included

This problem seems to occur when using the firmware-bnx2 package for the 
NetXTreme II cards. Once this firmware has been loaded, the 
openssh-server will start with a default oom_adj of -17, which then 
causes all child processes within ssh to have -17.

Devs at OpenSSH have said this is not a bug within openssh, and they are 
simply inheriting whatever default oom_adj is sent across. You can see 
on the below testing (one with bnx2, one without bnx2, under identical 
installs), that the oom_adj is different:

> root@vicky:~# cat /var/log/auth.log | grep "Set"
> May 30 21:41:05 vicky sshd[1568]: Set /proc/self/oom_adj from -17 to -17
> May 30 21:41:07 vicky sshd[1574]: Set /proc/self/oom_adj to -17
>
> root@vicky:~# ps faux | grep 1574
> root      1574  0.0  0.0  70488  3404 ?        Ss   21:41   0:00  \_ 
sshd: root@pts/1
>
> root@vicky:~# ps faux | grep "1568"
> root      1568  0.0  0.0  49168  1152 ?        Ss   21:41   0:00 
/usr/sbin/sshd
>
> In sshd.c there seems to be:
> static int oom_adj_save = INT_MIN;
>
> root@courtney:~/openssh-5.5p1# grep -R "Set %s to %d" .
> ./openbsd-compat/port-linux.c:          verbose("Set %s to %d", 
OOM_ADJ_PATH, oom_adj_save);
>
> Then I tried on a server with different network card hardware (as 
shown below), and got this from the logs:
>
> root@courtney:~/openssh-5.5p1# cat /var/log/auth.log  | grep "Set"
> May 30 21:50:15 courtney sshd[4821]: Set /proc/self/oom_adj from 0 to -17
> May 30 21:50:26 courtney sshd[4848]: Set /proc/self/oom_adj to 0
>
> root@courtney:~/openssh-5.5p1# ps faux | grep "4848"
> root      4848  0.0  0.0  70488  3372 ?        Ss   21:50   0:00  \_ 
sshd: root@pts/1
>
> root@courtney:~/openssh-5.5p1# ps faux | grep "4821"
> root      4821  0.0  0.0  49168  1160 ?        Ss   21:50   0:00 
/usr/sbin/sshd
>
> root@courtney:~/openssh-5.5p1# cat /var/log/auth.log  | grep -e "Set" 
-e "oom_adjust_restore"
> May 30 21:50:15 courtney sshd[4821]: Set /proc/self/oom_adj from 0 to -17
> May 30 21:50:26 courtney sshd[4848]: debug3: oom_adjust_restore
> May 30 21:50:26 courtney sshd[4848]: Set /proc/self/oom_adj to 0

The problem is, you can't test for this condition unless you physically 
have a bnx2 card installed, with the bnx2 drivers loaded (which you need 
the firmware iso for), so this will make it very hard for someone to 
confirm this bug.

Below is a full transcript from openssh:

So I modified the code to try and repair this oom_adj problem...

port-linux.c:
line 235: //static int oom_adj_save = INT_MIN;
line 236: static int oom_adj_save = 0;
line 277: verbose("Set %s to %d - sleepycal", OOM_ADJ_PATH, oom_adj_save);


I then ran compiled the package, ran SSHd, and yet we still have -17 in 
oom_adj_save. Wtf? Now, I'm not much of a C coder, but this is weird 
even in my books...

May 30 22:18:19 vicky sshd[12825]: Set /proc/self/oom_adj to -17 - sleepycal

So, I went all out crazy, and did the following patch:

        static int sleepycal_oom_adj_save = 0;
        verbose("sleepycal_oom_adj_save=%d", sleepycal_oom_adj_save);

        if (fprintf(fp, "%d\n", sleepycal_oom_adj_save) <= 0)
                verbose("error writing %s: %s", OOM_ADJ_PATH, 
strerror(errno));
        else
                verbose("Set %s to %d - sleepycal", OOM_ADJ_PATH, 
sleepycal_oom_adj_save);

And it worked!!! :)

May 30 22:27:12 vicky sshd[2532]: sleepycal_oom_adj_save=0
May 30 22:27:12 vicky sshd[2532]: Set /proc/self/oom_adj to 0 - sleepycal

root@vicky:~/openssh-5.5p1# cat /proc/2532/oom_adj
0

So, it turns out that it is actually OpenSSH which is broken, after 
almost 3 days of frustrating digging through millions of lines of code 
lol. Anyways, would appreciate if someone could get this merged into 
master (obv rename the vars if you want).

Attached is the appropriate patch file as of openssh-5.5p1

Cal

On 30/05/2011 21:56, Cal Leeming [Simplicity Media Ltd] wrote:
>  Just did some testing..
>
> root@vicky:~# cat /var/log/auth.log | grep "Set"
> May 30 21:41:05 vicky sshd[1568]: Set /proc/self/oom_adj from -17 to -17
> May 30 21:41:07 vicky sshd[1574]: Set /proc/self/oom_adj to -17
>
> root@vicky:~# ps faux | grep 1574
> root      1574  0.0  0.0  70488  3404 ?        Ss   21:41   0:00  \_ 
sshd: root@pts/1
>
> root@vicky:~# ps faux | grep "1568"
> root      1568  0.0  0.0  49168  1152 ?        Ss   21:41   0:00 
/usr/sbin/sshd
>
> In sshd.c there seems to be:
> static int oom_adj_save = INT_MIN;
>
> root@courtney:~/openssh-5.5p1# grep -R "Set %s to %d" .
> ./openbsd-compat/port-linux.c:          verbose("Set %s to %d", 
OOM_ADJ_PATH, oom_adj_save);
>
> Then I tried on a server with different network card hardware (as 
shown below), and got this from the logs:
>
> root@courtney:~/openssh-5.5p1# cat /var/log/auth.log  | grep "Set"
> May 30 21:50:15 courtney sshd[4821]: Set /proc/self/oom_adj from 0 to -17
> May 30 21:50:26 courtney sshd[4848]: Set /proc/self/oom_adj to 0
>
> root@courtney:~/openssh-5.5p1# ps faux | grep "4848"
> root      4848  0.0  0.0  70488  3372 ?        Ss   21:50   0:00  \_ 
sshd: root@pts/1
>
> root@courtney:~/openssh-5.5p1# ps faux | grep "4821"
> root      4821  0.0  0.0  49168  1160 ?        Ss   21:50   0:00 
/usr/sbin/sshd
>
> root@courtney:~/openssh-5.5p1# cat /var/log/auth.log  | grep -e "Set" 
-e "oom_adjust_restore"
> May 30 21:50:15 courtney sshd[4821]: Set /proc/self/oom_adj from 0 to -17
> May 30 21:50:26 courtney sshd[4848]: debug3: oom_adjust_restore
> May 30 21:50:26 courtney sshd[4848]: Set /proc/self/oom_adj to 0
>
>
>
>
> On 30/05/2011 21:30, Cal Leeming [Simplicity Media Ltd] wrote:
>> Hi all,
>>
>> Please find below a complete transcript of the emails between 
debian/kernel-mm mailing lists.
>>
>> I've had a response back from someone on the deb mailing list stating:
>>
>> ====================================
>> The bug seems to be that sshd does not reset the OOM adjustment before
>> running the login shell (or other program).  Therefore, please report a
>> bug against openssh-server.
>> ====================================
>>
>> Therefore, I am submitting this bug to you also.. If someone would 
be kind enough to have a flick thru all the below debug/logs, it'd be 
very much appreciated.
>>
>> Cal



========================================================
Hi,

On Mon, May 30, 2011 at 10:32:24PM +0100, Cal Leeming [Simplicity Media 
Ltd] wrote:
> So, it turns out that it is actually OpenSSH which is broken, after

I would not second this.  To me, this very much looks like:

> On 30/05/2011 21:56, Cal Leeming [Simplicity Media Ltd] wrote:
> > Just did some testing..
> >
> >root@vicky:~# cat /var/log/auth.log | grep "Set"
> >May 30 21:41:05 vicky sshd[1568]: Set /proc/self/oom_adj from -17 to -17
> >May 30 21:41:07 vicky sshd[1574]: Set /proc/self/oom_adj to -17

... it's reading out the old value, saving it, setting it to "-17" (for
the sshd listener process, that one is not to be killed), and later on
*restoring* the old value (for all child processes).  See the comments
in platform.c

The log messages look weird because the value is -17 already when sshd
starts - so it's adjusting "-17 to -17" and later on "restoring -17" -
looks stupid, but that's computers for you.  But what it tells you is
that the value isn't set by sshd to "-17" but that sshd inherited that
from whoever started it.

The question here is why sshd is sometimes started with -17 and sometimes
with 0 - that's the bug, not that sshd keeps what it's given.

(Ask yourself: if sshd had no idea about oom_adj at all, would this make
it buggy by not changing the value?)


Anyway, as a workaround for your system, you can certainly set

 oom_adj_save = 0;

in the beginning of port-linux.c / oom_adjust_restore(), to claim that
"hey, this was the saved value to start with" and "restore" oom_adj to 0
then - but that's just hiding the bug, not fixing it.

gert
--
USENET is *not* the non-clickable part of WWW!
                                                          
//www.muc.de/~gert/
Gert Doering - Munich, Germany                             
gert@greenie.muc.de
fax: +49-89-35655025                        
gert@net.informatik.tu-muenchen.de

Message #10 received at 628690@bugs.debian.org (full text, mbox, reply):

From: "Cal Leeming [Simplicity Media Ltd]" <cal.leeming@simplicitymedialtd.co.uk>

To: 628690@bugs.debian.org

Subject: Re: Bug#628690: Acknowledgement (openssh-server inherits oom_adj -17 upon start under specific conditions, causing DoS potential for oom_killer)

Date: Tue, 31 May 2011 13:43:35 +0100

Here is the latest conversation with openssh devs, which confirms this 
definitely falls within the remit of debian or kernel-mm.

On 31/05/2011 13:25, Gert Doering wrote:
> Hi,
>
> On Tue, May 31, 2011 at 12:11:13PM +0100, Cal Leeming [Simplicity 
Media Ltd] wrote:
>> Could you point out the line of code where oom_adj_save is set to the
>> original value, because I've looked everywhere, and from what I can
>> tell, it's only ever set to INT_MIN, and no where else is it changed.
>> (C is not my strongest language tho, so I most likely have overlooked
>> something). This is where I got thrown off.
>
> oom_adjust_setup() does this:
>
>                 if ((fp = fopen(oom_adj_path, "r+")) != NULL) {
>                         if (fscanf(fp, "%d", &oom_adj_save) != 1)
>                                 verbose("error reading %s: %s", 
oom_adj_path,
>                                     strerror(errno));
>
> the "fscanf()" call will read an integer ("%d") from the file named,
> and write that number into the variable being pointed to (&oom_adj_save).
>
> The loop is a bit tricky to read as it takes different paths into
> account, and will exit after the first successful update.
>
> fscanf() will return the number of successful conversions, so if it
> was able to read "one number", the return value is "1", and it will
> jump to the else block
>
>                         else {
>                                 rewind(fp);
>                                 if (fprintf(fp, "%d\n", value) <= 0)
>                                         verbose("error writing %s: %s",
>                                            oom_adj_path, 
strerror(errno));
>                                 else
>                                         verbose("Set %s from %d to %d",
>                                            oom_adj_path, 
oom_adj_save, value);
>                         }
>
> where it will overwrite what is in that file with the new value
> ("value"), and then print the "Set ... from -17 to -17" message that
> you saw.

Ah, thank you for explaining this. Makes a lot more sense now :)

>
>
>>> The question here is why sshd is sometimes started with -17 and 
sometimes
>>> with 0 - that's the bug, not that sshd keeps what it's given.
>>>
>>> (Ask yourself: if sshd had no idea about oom_adj at all, would this 
make
>>> it buggy by not changing the value?)
>>
>> This was what I was trying to pinpoint down before. I had came to this
>> conclusion myself, sent it to the Debian bug list, and they dismissed
>> on the grounds that it was an openssh problem...
>
> I must admit that I have no idea what is causing it, but from the logs,
> it very much looks like sshd is started with "-17" in there - but only
> in the problem case.
>
>
>> So far, the buck has been passed from kernel-mm to debian-kernel, to
>> openssh, and now back to debian-kernel lol. The most annoying thing,
>> is that you can't get this bug to happen unless you physically test on
>> a machine which requires the bnx2 firmwire, so I get the feeling this
>> won't get resolved :/
>
> And *that* strongly points to a bug in the bnx2 stuff - if other programs
> change their behaviour based on the existance of a given driver, that
> does not smell very healthy.

Agreed.. I was thinking of adding some debug into the fs/proc/ code 
which does a kprint on every oom_adj read/write, but I couldn't figure 
out how to extract the pid from the task (pointer?).

>
> [..]
>>> Anyway, as a workaround for your system, you can certainly set
>>>
>>>  oom_adj_save = 0;
>>>
>>> in the beginning of port-linux.c / oom_adjust_restore(), to claim that
>>> "hey, this was the saved value to start with" and "restore" oom_adj 
to 0
>>> then - but that's just hiding the bug, not fixing it.
>>
>> I'm disappointed this wasn't the correct fix, I honestly thought I had
>> patched it right :(
>
> Well, that's the short hand - "just ignore everything that happened at
> init / save time, and forcibly write back '0', no matter what was there
> before".
>
>> But, on the other hand, ssh users should really never have a default
>> oom_adj of -17, so maybe 0 should be set as default anyway? If this is
>> not the case, could you give reasons why??
>
> Well, I would say "the default value in there is a matter of local 
policy",
> so what if someone wants to make sure that whatever is run from sshd is
> always privileged regarding oom, even if a local firefox etc. is running
> amock and you need to ssh-in and kill the GUI stuff...
>
> One might opt to run sshd (and all its children) at "-5" (slightly 
special
> treatment), or "0" (no special treatment), or even at "-17" - but that's
> local policy.

Ah, okay that's make sense.

>
>
> Mmmh.
>
> Since this seems to be inherited, it might even work if you just change
> the sshd startup script, and insert
>
>   echo 0 >/proc/self/oom_adj
>
> in there, right before it starts the sshd...  "local policy at work".

Yeah I was going to do this, but then I thought "well if this problem is 
occurring for openssh, then what else could it be affecting?". As you 
pointed out above, having the oom_adj changed based on the existence of 
a driver is really not good.

I will paste this convo trail into the debian ticket, and hopefully 
it'll help convince them this issue needs fixing.

>
> gert

Thanks again for taking the time to reply!




On 31/05/2011 12:24, Debian Bug Tracking System wrote:
> Thank you for filing a new Bug report with Debian.
>
> This is an automatically generated reply to let you know your message
> has been received.
>
> Your message is being forwarded to the package maintainers and other
> interested parties for their attention; they will reply in due course.
>
> Your message has been sent to the package maintainer(s):
>   Debian OpenSSH Maintainers<debian-ssh@lists.debian.org>
>
> If you wish to submit further information on this problem, please
> send it to 628690@bugs.debian.org.
>
> Please do not send mail to owner@bugs.debian.org unless you wish
> to report a problem with the Bug-tracking system.
>

Message #15 received at 628690@bugs.debian.org (full text, mbox, reply):

From: Dave Chinner <david@fromorbit.com>

To: 628690@bugs.debian.org

Subject: sshd children inherit OOM adj from context sshd is started from

Date: Mon, 5 Dec 2011 09:25:56 +1100

I just hit this problem with sshd randomly starting child processes
with oom_adj_score of either -1000 or 0, resulting in unpredictable
oom killer behaviour on my test rigs.

Turns out the problem is a combination of openssh behaviour and a
race in the debian startup scripts.

Firstly, the startup race is described in #502444 - ifup will
restart the ssh server when an interface comes up due to the
allow-hotplug rule. This appeaers to have been changed from a reload
because of problems with the start-stop-daemon handling concurrent
start/reload races sanely.

Regardless of whether that was the right fix, ssh sessions -
children of the sshd process - inherit whatever oom_adj_score the
context that the sshd process was started in. That is, if you start
it from the startup scripts, it has a value of 0. If it is started
from udev (due to allow-hotplug and dhcp), then it will be started
with a value of -1000, as udev modifies it's own value to avoid oom
killer invocations on it. If you run 'service sshd restart" from a
context with a value of X, then all future sshd session will run
with a oom_adj_score of X.

This is simply wrong behaviour - sshd children should always start
with a consistent oom_adj_score, not that inherited from it's
startup context. That, I think, is the source of the bug, and what
needs to be corrected. It seems the kernel folk and the aopenssh
folk are right - this is a distro problem.

This consistent startup environment problem be handled entirely in
the /etc/init.d/sshd startup script via reseting the oom_adj_score
to zero. If admins what a custom value, this can easily be done via a
variable in /etc/default/sshd. It's a simple fix, and then sshd will
always start child processes with a consistent environment
regardless of the context it was started from....

Further details of the analysis of the problem is here:

https://lkml.org/lkml/2011/12/1/563

And the full thread starts here:

https://lkml.org/lkml/2011/12/1/96


Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Send a report that this bug log contains spam.