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

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!

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.