appserver isn't recovering like it should causing too many oopses

This happened twice this week. Once on Monday after adding two new appservers for sso. And once today, cause still unknown.

We had another incident causing another bunch of oopses today, 05/05, and elmo restarted lpnet again. flacoste said stub will work on a fix for this bug this week (not today - holiday for him).

Causing outages on lpnet

Merged on rev 122 of our storm branch.

The fix isn't working.

We do have a better understanding of what is happening. https://pastebin.canonical.com/17341/ shows a bunch of InterfaceError OOPS that happens. We see that one stretch of OOPS begins at OOPS-I2432. If we look at the previous OOPS-I2431, we see that an OperationalError was raised during the call to set_statement_timeout. Because that method doesn't use the _check_disconnect wrapper, the error is uncaught and leaves the connection in a disconnected state.

The following request gets an InterfaceError because of this. The suggested fix isn't enough because is_disconnection_error() is only called when the error is a subclass of DatabaseError. This isn't the case for InterfaceError.

We have no idea why the initial OperationError is happening. What is weird is that the client reports that the server disconnects it, but on the server, we see that it closes the client socket two minutes after the error. See https://pastebin.canonical.com/17342/ (to compare the timestamps).

I think Francis meant OOPS-1223I2432 and OOPS-1223I2431 respectively.

In https://devpad.canonical.com/~matsubara/bug-360846-oops-summary.html you can find a oops summary for the lpnet9 (oops_prefix: I) instance only, between 2009-05-07 21:33:00UTC and 2009-05-07 21:39:00UTC

The 5 OperationalError have one thing in common, they're all nagios checks.

In https://devpad.canonical.com/~matsubara/2009-05-07-tmp-summary.html, we see a similar pattern. This OOPS report spans the 50 minutes after the restart of lpnet9 before InterfaceError starts creeping up.

i would just to add that even OpenID is failing too (maybe timeouts?), making it hard to even login to the wiki pages (and other services users use OIP with)

I correlated the information from app server launchpad9.log (lpnet9 -- oops_prefix: I) restart times (restart times in BST) with oops summaries (oops summaries times in UTC). All of these summaries are from the time the app server was restarted until the first OE/IE error is raised.

2009-05-07T04:37:48 INFO Server zope.server.http (HTTP) started.
https://devpad.canonical.com/~matsubara/bug-360846-summaries/2009-05-07-03:37:48--06:05:00.html
2009-05-07T09:40:49 INFO Server zope.server.http (HTTP) started.
https://devpad.canonical.com/~matsubara/bug-360846-summaries/2009-05-07-08:40:49--16:56:00.html
2009-05-07T20:40:52 INFO Server zope.server.http (HTTP) started.
https://devpad.canonical.com/~matsubara/bug-360846-summaries/2009-05-07-19:40:52--21:28:00.html
2009-05-07T22:38:11 INFO Server zope.server.http (HTTP) started.
https://devpad.canonical.com/~matsubara/bug-360846-summaries/2009-05-07-21:28:11--23:59:59.html

Fix merged to Storm's trunk in r305

The appropriate fix was cherry-picked on Friday evening.

Automatic recovery of further problem is described in bug 374909.