Subject: Outage

From: Glen <[email-masked]>
Date: Mon, 12 May 2008 09:29:01 -0700

All -

Last night we had another outage.  This outage was identical in every
respect to the outage last week.  It occurred with exactly the same log
entries, at exactly the same time - to the minute - that the outage last
Wednesday night/Thursday morning happened.

On the good side, we know that the hardware - which is brand new - is
not failing.  There are detailed log entries that show that the server
is overloading and oom-killing processes.  The server itself stays up,
but kills off so many processes that public things, such as web and
email and so forth simply stop working.  And, because I installed remote
power control Thursday, Matt was able to power-cycle the server remotely
and get us back online much more quickly.

On the bad side, this is the second time this has happened, and the only
thing we've changed recently - and the thing that the evidence points to
- is the addition of TMDA to all of the mailing lists.

The problem is that, although this has happened at exactly the same time
each night, that is the only pattern so far.  After Thursday's outage, I
have personally sat up with the machine each night and watched it run
with no problems well past midnight... except for (you guessed it!) last
night, when, after several nights with no problem, I figured that the
re-tuning of processing rates and limits had solved the problem, and
went to bed at a slightly more reasonable time.

*sigh*

Of course, I've gone through all the obvious things.  Nothing
specifically abnormal is running at that particular time on our end - no
cron jobs or anything like that.  We run backups, syncs, updates, etc.,
every hour throughout the day and night, so nothing special is happening
on our end at 23:50 local time to cause this.  But clearly, something is
going on at that time to cause us grief - at least on Sundays and
Wednesdays.  (Note, of course, that these are local times here - they
translate into Monday and Thursdays at 06:50 GMT, if I'm doing that
conversion correctly.

I'm pretty confident that by taking TMDA back offline, this problem
would go away.  However, I don't want to do this, and I know most of YOU
don't want that either.   What I'd really like to do is catch this thing
in the act, and find out what's going on and why.  Unfortunately, that,
too, may be unreasonable.

So, I'll be spending the rest of the day trying to find other clues as
to what's happening.  And we're then going to deploy a second server,
and assign all of the mail processing functions to it:  Incoming mail
handling, virus checking, spam scanning/tagging, and TMDA.  This is
going to take a couple of days to accomplish correctly, of course, but
this is the plan we have right now.  Between now and then, I will stay
up with the server each night at least until after 23:50, to try to
ensure that no more outages occur (at least not at that time.)

Heretofore, the server running the IETF has barely been breathing hard
at all.  I cannot believe that the addition of TMDA is causing this much
trouble... although TMDA is by its own author's admission not really
designed for this kind of volume.  It grates on me to think that this
can somehow push this huge server over the edge.  However, as I watch
TMDA run, it does seem to consume quite a bit of time and resources, and
does seem to be rather a dog.

Anyway, as I said, we're going to split these functions off onto another
server.  We'll make this transition as quick and painless as possible,
and, hopefully, that will be the end of it.

Please remember that I am not on the wgchairs lists, so if anyone has
anything to offer, please be sure to reply-all or at least include me.
Thanks for your patience during this time of adjustment and growth.

Glen Barney
IT Director
Association Management Solutions

---

From: Henrik Levkowetz <[email-masked]>
Date: Mon, 12 May 2008 21:30:51 +0200

Hi Glen, all,

On 2008-05-12 18:29 Glen said the following:
...
> does seem to be rather a dog.

I guess it really should be running as a daemon.  I don't know how easy that
would be to accomplish, but it's at least worth checking if anybody has looked
at it before, and also how hard it would be to do a daemonization wrapper.
I'll have a peek.

	Henrik

---

From: Joel Jaeggli <[email-masked]>
Date: Mon, 12 May 2008 12:46:46 -0700

> at it before, and also how hard it would be to do a daemonization wrapper.

If you're running it as part of local delivery just doing a little 
locking will put enough backpressure on it to keep it from spamming you 
with processes.

---

From: Henrik Levkowetz <[email-masked]>
Date: Mon, 12 May 2008 22:18:42 +0200

...

> locking will put enough backpressure on it to keep it from spamming you 

Which should avoid the crash & burn.  But the startup cost of interpreter
+ module loading is still there -- I'd love to bring that down, so TMDA
isn't so costly per invocation.

This looks promising: http://readyexec.sourceforge.net/ -- it will let
you set up a lightweight client / unix domain socket / server architecture
for any python function which takes its input and arguments from stdin and
the environment, which is the case for tmda.

	Henrik

---

From: Glen <[email-masked]>
Date: Mon, 12 May 2008 16:21:43 -0700

Thanks to all of you for your helpful commentary today.  My apologies 
for not replying individually, but please bear with me as I cover a few 
things.

Jim Galvin suggested concurrency limits.  Excellent idea.  Alas, we 
already have that in place:

smtpd_client_connection_count_limit = 1
smtpd_client_connection_rate_limit = 4
smtpd_client_event_limit_exceptions = 
${smtpd_client_connection_limit_exceptions:$mynetworks}

In a private message, I was told:

> Ordinarily I would just let you handle this, but you did ask if people
> had anything to offer, so...

Absolutely.  My job is just to keep things running as smoothly as 
possible and take care of requests from you, the community 
representatives, as efficiently as I can.  So I'm always appreciative of 
thoughts and ideas when things like this happen.  I've got several Linux 
engineers here, but we are always interested in other ideas.

Same sender:
> - I assume that "oom" is out of memory. Unix systems don't typically
>   kill processes when the box starts running low on memory. They just
>   thrash a lot as more and more of the system starts to reside 
>   outside of RAM. So, if you're seeing processes get killed, it's
>   probably because those processes overflowed the maximum memory
>   size, in which case you've got a pretty good guess that something
>   is severely wrong with those processes. So, what's failing?

Yes, I remember those days.  Actually, our system (OpenSuse 10.3), and, 
apparently, new systems, have something called "oom_killer"

http://linux-mm.org/OOM_Killer

which is what started running at 23:50 each of those two nights and 
killing things.

May 11 23:50:28 core3 tmda-wrapper: User: nobody
May 11 23:50:28 core3 tmda-wrapper: USER     : magma
May 11 23:50:28 core3 tmda-wrapper: USER     : magma-request
May 11 23:50:28 core3 tmda-wrapper: SENDER   : [email-masked]
May 11 23:50:28 core3 tmda-wrapper: SENDER   : [email-masked]
May 11 23:50:28 core3 tmda-wrapper: RECIPIENT: [email-masked]
May 11 23:50:28 core3 tmda-wrapper: RECIPIENT: [email-masked]
May 11 23:50:28 core3 tmda-wrapper: EXTENSION:
May 11 23:50:28 core3 tmda-wrapper: EXTENSION:
May 11 23:50:28 core3 tdma-wrapper:  * Input piped to tmda-filter
May 11 23:50:28 core3 tdma-wrapper:  * Input piped to tmda-filter
May 11 23:50:31 core3 kernel: find invoked oom-killer: gfp_mask=0xd0, 
order=1, oomkilladj=0
May 11 23:50:31 core3 kernel:  [<c0159b2a>] out_of_memory+0x69/0x1a7
May 11 23:50:31 core3 kernel:  [<c015b0be>] __alloc_pages+0x219/0x2d6
May 11 23:50:31 core3 kernel:  [<c01d7ec3>] copy_to_user+0x25/0x3a
May 11 23:50:31 core3 kernel:  [<c015b1a7>] __get_free_pages+0x2c/0x3a

Lots of TMDA stuff runs just before the oom-killer, then LOTS of entries 
for the oom-killer, and so forth and so on, until even syslog gets killed.

In the old days, I've seen systems thrash and thrash and I could still 
log in and recover them if I was willing to wait 5 minutes for a shell. 
  Then a quick "nice --19 sh" got me some access.

But this oom_killer thing kills of syslogd, sshd, crond, apache, 
postfix, etc., until the system "is happy" again.  So the server doesn't 
really "go down" - but, for all intents and purposes, it is the same thing.

As an option, I'm looking into ways of disabling this process.  So far, 
no luck - the required /proc entries are missing on core3.  But I will 
keep looking.

> - Do you have more detailed process logs? The natural thing to
> - Have you tried turning on process accounting? That will tell
> - Can you take tcpdumps around the time to see if there's some
> - As a last ditch, why not just have a watchdog process on another

One of the things we wanted to do during the cutover was setup nagios 
and/or other monitoring processes to do this work.  Time did not permit 
us that option.  I have one of my engineers working on that now, and it 
should be ready in a day or two.

I, of course, still want to determine the cause.  So I'm also 
implementing those suggestions as appropriate for this situation - all 
of which were excellent.

Henrik wrote:

> Not that I can see.  I have only 2 cronjobs which do external accesses once
> per day, at local time (now CEST) 07:00 and 16:30.  Other cron jobs run once
> per hour, the heaviest of those starts at NN:45 (45 minutes after the hour
> every hour).

"The heaviest" would then be starting five minutes before the server ran 
out of memory...

... but again, things have been running just fine from the beginning, 
until this week.

I have a job that started at 11:30 PM... it's a find on the entire 
filesystem, so I thought, maybe that was the problem.  But I ran it 
today by hand, and it took 8 minutes and ran with no visible resource 
impact.

Henrik then said:

> I guess it really should be running as a daemon.  

> locking will put enough backpressure on it to keep it from spamming you 

I'm much more in favor of this.  Daemonization is over-working it a bit, 
  but having messages spin on a lock file makes much more sense to me. 
I think something like that could be written in to the initial wrapper 
we're using, and I will consult privately with the author about that.

Finally, Jari wrote:
> I feel your pain.

THANK YOU, Jari, for your support.

We're just trying to accommodate everything the IETF wants here.  It's 
VERY frustrating and stressful to have a brand new huge server start 
failing without clear cause in the middle of the night.  So be assured 
we're all scrambling here to get this resolved as quickly as possible.

For now, I really would like to try to solve the problem directly rather 
than just throw another server at it.  I have a second server, right 
next to the first, equally big (8 3GHz cores, 8GB Ram, 2x 300GB mirrored 
drive arrays, 1333 bus, etc. etc.) sitting as a hot backup for the 
production machine - it is not a far cry to reorganize that machine to 
be the mail exchanger server and let it bear that load.

But the bottom line is that "normally", this big huge server runs at a 
load average of less than 4, with 3-6% of CPU utilized, and 25% of RAM 
utilized, and that's the case even during cron jobs.  So for this server 
to start running oom-killer, something particularly ugly must be 
happening.  And I don't want to just "cover up" that problem by throwing 
another $10,000 server at it.  I really want to *find* the problem and 
fix it.

Which will take several days of watching, and the potential for another 
crash or two, but which, I think, is worth it.

I don't want to just "dismiss" a problem like this (or any problem.)  I 
want to solve it.

So unless there is strong objection, my plan is to put in the additional 
monitoring we've all discussed, and watch and see if we can "catch this 
in the act" again.  If everyone is willing to go along with that plan, I 
think it will provide the best possible outcome.

And if we find nothing else after several days, I'll bring that second 
server online as an inbound mail processor, and see how THAT goes.

Thank you all, again, for your support with this matter.

Glen

---

From: Glen <[email-masked]>
Date: Tue, 13 May 2008 00:09:46 -0700

All -

Good morning.

At 06:55 GMT - five minutes past the time of our two outages this past 
week - the server is running quite smoothly and unencumbered, and has 
not (at least so far) gone down or shown any signs of doing so.

Progress was definitely made today.  Things we did include such elements 
as:  (Suppressing the desire to work "Fear" and "Surprise" into this 
message)...

* Did a bunch of digging through the kernel.  Found some strangeness in 
the way memory was being handled generally, found a possible way of 
adding some sanity to the oom-killer process, re-tuned the kernel to 
implement and fix that.

* In concert with Henrik, installed a modified version of the TMDA 
handler to fine-tune how TMDA is dispatched, thus reducing significantly 
the added load from TMDA (with great success, thank you Henrik!)

* Installed a logging system to capture snapshots of all kind of server 
data and log it; in the event that the server -does- go down this will 
hopefully give us something more to look at.

* Found a way to exempt certain processes from the oom-killer, applied 
those exemptions to the syslog and cron and sshd processes.  I -hope- I 
never get to test this, but I applied it nonetheless.

And of course,

* Sat up with the machine until now, to watch firsthand what is happening.

I did see a lot of python activity, and a lot of datatracker activity, 
and that activity increased dramatically after 06:30Z.  TMDA activity 
also increased dramatically; the new handler performed very well and our 
overall load remained low.  The usual other things all ran correctly and 
as they should, and the server performed perfectly, averaging less than 
2% cpu, peaking at 17% at one point, with memory staying well below the 
50% mark throughout the night.

So did these changes solve the problem?  The re-tuning and the TMDA 
stuff -may- have.  I won't stay up every night, but I *will* stay up 
Wednesday-into-Thursday again, since that's when the last crash 
occurred, just to see what happens.... and we'll go from there.

I also found a way to have the oom-killer reboot the server if it gets 
into that much trouble.  I haven't turned that on yet; however, when 
this little episode is all done, I will turn it on, so that any failures 
of this type in the future are hopefully limited to a few minutes of 
automatic recovery, rather than outages like this.

Have a good night/day as appropriate, and, if nothing happens between 
now and then, I'll post another email Thursday.

Glen Barney

---

From: Glen <[email-masked]>
Date: Tue, 13 May 2008 10:23:00 -0700

Jeffrey Hutzelman wrote:
> The key point here is that the problem is not that you are running the 
> system out of VM, but that you are exhausting the memory available for 
> kernel data structures which cannot be swapped out.

I saw suggestions of this during my research of the oom-killer 
yesterday.  That was what was bothering me - because there was no way I 
could think of that an addition 4GB of RAM could be consumed so quickly. 
  But when I considered the page structures - aHA! - that made more 
sense.  So I modified min_free_kbytes and cranked it up to hold more 
memory open for the kernel memory tables.  (Against my thinking, this 
seems to me to be the most correct choice.  I'll feel better about this 
after Wednesday night / Thursday.  :-)  )

> The oom killer also applies a weighting algorithm intended to kill less 
> important processes and bigger memory users first.  If it is killing 
> daemons like sshd, cron, and syslog, then it is getting pretty desperate.

Yeah, I looked at the process scores.  Some of them seemed to be quite 
random.

> Good, because throwing another server at it likely won't solve the problem.

I agree completely!

> You may be able to do one better.  If you set the sysctl parameter 
> vm.panic_on_oom to 2 (do this in /etc/sysctl.conf, if SuSE has that, or 
> else echo 2 into /proc/sys/vm/panic_on_oom), then the system will panic 
> instead of starting to kill processes.  This may result in a usable 
> backtrace in the system logs, will result in a crash dump if you have 
> crash dumps enabled, and will also eventually result in a reboot, if you 
> have set a nonzero panic timeout (this is the value of the sysctl 
> parameter kernel.panic, in seconds; the default is 0, which disables 
> automatic reboot).

Yes, thanks.  I had set that up but left it commented out last night, 
but I think I'll just go ahead and apply it:

kernel.panic=5
kernel.panic_on_oops=1
vm.min_free_kbytes=16384
vm.panic_on_oom=2

But I'm going to turn it back off briefly Wednesday night.  In the event 
that something bad is happening on schedule, I still want to try to 
catch it in the act.  :-)

THANK YOU for these additional comments!

Glen

---

From: Glen <[email-masked]>
Date: Tue, 13 May 2008 11:31:41 -0700

Eric Rescorla wrote:
> So, this is still puzzling. What's going on at 0630 to cause increased
> processing?

I agree.

Based on everything, I am guessing that:

1. Things were already busy at that time (outside cron jobs running 
against the datatracker, spam runs. etc.)
2. The addition of TMDA increased the loading effect of the spam runs on 
the server.
3. The need for additional memory page buffers caused the oom-killer to 
start up, which, in turn, partially shut down the server.

Based on that, I hoping that:

1. The new TMDA script will more correctly engage TMDA (i.e. bounces 
were going through it before, now they are not.)
2. The memory adjustments I made will keep the server from running out 
of buffers.
3. The availability of buffers will keep the oom-killer from starting.

And of course, if that fails:

1. I've set the system to panic instead of oom-killing, and
2. I've set the system to reboot on panic, so
3. If this problem happens again, it should recover itself with just a 
reboot.

Glen

---

From: Glen <[email-masked]>
Date: Thu, 15 May 2008 20:42:40 -0700

All -

I wanted to take a moment and post a final message regarding our recent 
outage, to let everyone know how things concluded and what we did about 
this.

As you recall, the problem began shortly after we "upgraded" the system 
to include TMDA processing for all of the IETF lists.  Two nights after 
applying that upgrade, we had a significant outage; then we had an 
additional shorter outage several days later.

Having spent quite a bit of time researching and discussing our 
findings, I've drawn the conclusion that the server crashed because it 
ran out of kernel page table memory.  The server itself is quite huge - 
with 8 processor cores running at 3GHz, 8GB of RAM, dual 300GB mirrored 
drive arrays, and so forth.  But a comparatively small portion of memory 
is used to manage all the rest of the memory in the system, and that 
small portion became exhausted as a result of the increased process load 
brought in by TMDA.

TMDA was not in itself the direct cause of the failure, TMDA was the 
"straw", so to speak.  The direct cause of the failure was that a key 
section of kernel memory became exhausted, and the server attempted to 
shut down processes to recover that memory.  This caused most public 
services (web, email, FTP) to be shut down, in essence causing the 
outage.  The server itself was still up and running... but no public 
processes were running... so the end result was the same.

Once we realized what had happened, the solution was quite easy - we 
simply increased (dramatically) the size of the memory area used by the 
kernel, to more than twice the maximum size needed to operate all of the 
existing services.  Observation of the server under regular load after 
this adjustment seems to have confirmed that this adjustment did in fact 
resolve the problem, and we have made these adjustments permanent on all 
IETF servers.

Another issue relating to the outage was the overall time of the outage. 
  In order to reduce the time of the outage, I've already implemented 
additional steps, such as the installation of remote power control, and 
remote server console access, on all IETF servers.  This, obviously, 
allows us to immediately interact with and restore a failed server, 
without the need to send on-call staff to the site in the middle of the 
night.  We had already planned these additions; however, because of the 
large volume of work pushed from "during cutover" to "post cutover", 
those items had not yet been implemented.  In consultation with AMS 
owners, I took those items to the top of the list and implemented them 
personally.

In addition, again thanks to commentary from the community, I've 
implemented additional kernel changes on the IETF servers.  Going 
forward, the server will no longer be permitted to selectively kill 
processes in an out-of-memory condition.  Instead, the server will 
execute an immediate reboot.  Moreover any type of software-based 
failure of this type (an "oops" or panic) will also now result in an 
immediate reboot.

Another project on our "to-do" list was the implementation of server and 
system monitoring software.  Again, this was planned for the transition 
period, but timing constraints forced us to delay this important 
component.  We have now implemented the popular NAGIOS system across our 
Fremont data center, and are configuring its quite complex test set and 
extending the system to our Orlando data center this coming week.

Obviously, all of these changes together will dramatically reduce the 
potential length (and possibility!) of any future outages.

Finally, the topic was raised about additional servers.

We currently operate four servers dedicated to the IETF.  Each is 
configured and built as I outlined above.  One server currently 
functions as the primary operations server, and handles all of the 
IETF's traffic without ever really breathing hard.  The recent failure, 
of course, is an exception, but that was a kernel utilization issue, 
which was a rather unique thing, and not an overload of the server's 
hardware resources.  Each one of the servers we've assigned to the IETF 
is the processing and power equivalent of three servers used by the 
former provider.  I was confident that a single server could handle all 
of the operations of the IETF, and I still am.

Indeed, I agree strongly with the comment someone made that "throwing 
another server at this won't solve the problem."  That turned out to be 
correct.  OTOH, I also agree strongly with the comment about not 
"putting all of our eggs in one basket."

So as I was saying, we have four servers, two in each of two data 
centers, and are currently running in such a way that an instant 
failover can be initiated to any of the other servers as desired, in the 
event of a longer-term or hardware failure of the production server.  So 
we have four identical eggs in two identical baskets, as it were.

In addition, we are planning to implement a fifth offsite backup server 
at ISOC, which will again be identical in function to the other four.

But I am more than open to the concept of putting in additional servers 
should the need arise.  One person commented today about adding 
additional mail exchange servers.  This is another comment I agree with; 
therefore, in the coming weeks I'll be setting up an additional server 
in Fremont to handle just incoming mail processing.  Obviously, that 
will not happen overnight, but it is something we will do going forward.

So, this outage, while unexpected, was not particularly catastrophic. 
No data was lost, the outage cause was identified and corrected, and 
we've taken appropriate steps to mitigate future outages and bring them 
under much more manageable levels.

Of course, my personal vote would be to never have an outage again.

I hope this information is useful and informative, and brings to closure 
any open questions regarding this outage.  TMDA remains in place, thanks 
primary to the efforts of Henrik Levkowetz, and the servers are running 
smoothly.  In addition, I wish to thank everyone who provided support 
and commentary during this highly stressful time.  Thank you all.

I'm now "closing this ticket," but please feel free to contact me at any 
time if you have further questions or concerns.  Please be reminded that 
I am not on the WGChairs list; therefore, you'll need to CC me if you 
want me to see something.

Best regards,
Glen Barney

---

From: Glen <[email-masked]>
Date: Fri, 16 May 2008 11:50:58 -0700

All -

Okay, having read all the email, and getting follow-up fom Jim and Russ, 
I think it's become clear that we are willing to face the burden of a 
potential increase in spam (lower case! ;-) ) to release these two other 
checks.

As such, I have now removed those checks, and we should be good to go.

A few closing points -

TOM PETCH - THANK YOU for taking the time to explain the consensus 
process to me, and your views on its operability.  I found that message 
to be extremely valuable, and I greatly appreciate it.

DANNY - Thanks for catching the IPV6 thing!  I'll get that blocked later 
today.  (I don't think that's been widely-used yet, and I hadn't even 
considered it, but you are quite right, and I very much appreciate you 
pointing that out.)

ERIC - Thanks for being the pro-forma guinea pig here, and taking the 
time to explain your position so clearly.

As for the list moderation messages, those occurred because we were all 
group-copying everyone on this thread, and mailman apparently doesn't 
like messages with "too many recipients."  I've released the last of the 
held messages (including my own, and this one, momentarily!) and that 
should do it.

Finally, I saw mention of interest in creating a web page that could 
provide bypass mechanisms to contact the IETF.  I'm referring that back 
to Jim Galvin to discuss with your ED, Alexa Morris.

As a point of interest, we do have the full ability to bypass individual 
senders, hosts, clients, recipients, etc., from being subject to these 
or any tests.  For example, if it was decided that you wanted one or 
more of these checks put in place, but you wanted all mail "TO" 
[email-masked] (or whatever) to be exempted from the checks, that is easily 
easily done.  Just say the word.

For now, the other two problematic checks have been removed, and, 
barring further direction, I'll "close this one out" on that note!

As always, feel free to contact me at any time for any reason.

Warm regards,
Glen Barney
Server Servant
AMS