DistroSeries:+queue Timeout accepting packages (bug structural subscriptions)

More oops:

(Error ID: OOPS-1916T11)
(Error ID: OOPS-1916F20)

These were accepting two packages (second was a retry of the first).

Doing them one at a time worked for one of them.

(Error ID: OOPS-1916R19)
(Error ID: OOPS-1916V18)
(Error ID: OOPS-1916Q18)

Gave up after three tries on the second.

568. 7956 21ms SQL-launchpad-main-master
SELECT 1
FROM
  (SELECT PackageDiff.date_fulfilled, PackageDiff.date_requested, PackageDiff.diff_content, PackageDiff.from_source, PackageDiff.id, PackageDiff.requester, PackageDiff.status, PackageDiff.to_source
   FROM PackageDiff
   WHERE PackageDiff.to_source = 952513LIMIT 1) AS "_tmp" LIMIT 1
569. 7979 2797ms SQL-launchpad-main-master
SELECT PackageDiff.date_fulfilled,
       PackageDiff.date_requested,
       PackageDiff.diff_content,
       PackageDiff.from_source,
       PackageDiff.id,
       PackageDiff.requester,
       PackageDiff.status,
       PackageDiff.to_source
FROM PackageDiff
WHERE PackageDiff.to_source = 952513
ORDER BY PackageDiff.date_requested DESC

SELECT 1
FROM
  (SELECT PackageDiff.date_fulfilled, PackageDiff.date_requested, PackageDiff.diff_content, PackageDiff.from_source, PackageDiff.id, PackageDiff.requester, PackageDiff.status, PackageDiff.to_source
   FROM PackageDiff
   WHERE PackageDiff.to_source = 952513LIMIT 1) AS "_tmp" LIMIT 1
explain analyze SELECT PackageDiff.date_fulfilled,
       PackageDiff.date_requested,
       PackageDiff.diff_content,
       PackageDiff.from_source,
       PackageDiff.id,
       PackageDiff.requester,
       PackageDiff.status,
       PackageDiff.to_source
FROM PackageDiff
WHERE PackageDiff.to_source = 952513
ORDER BY PackageDiff.date_requested DESC
SELECT PackageDiff.date_fulfilled,
       PackageDiff.date_requested,
       PackageDiff.diff_content,
       PackageDiff.from_source,
       PackageDiff.id,
       PackageDiff.requester,
       PackageDiff.status,
       PackageDiff.to_source
FROM PackageDiff
WHERE PackageDiff.to_source = 952513
ORDER BY PackageDiff.date_requested DESC

Here's some more oops:

(Error ID: OOPS-1931CG54)
(Error ID: OOPS-1931I568)

Those were for trying to accept 4 packages. Accepting them individually worked.

Seems to have gotten worse again.

(Error ID: OOPS-1932BC487)

That's with only two packages and last night I was unable to accept chromium-browser by itself on three tries (sorry, didn't save the OOPS numbers as I was in a hurry).

Looks like the problem child is audacity.

Error ID: OOPS-1932CM427
Error ID: OOPS-1932CO462
Error ID: OOPS-1932AU494

1200 statements longest 225ms
96 bugsubscription lookups (130ms)
110 batched person-with-account lookups (420ms)
56 archive lookups (80ms)
56 distroarchseries lookups(60ms)
43 individual person-with-account lookups (100ms)
43 packageuploadcustom lookups (70ms)
42 packageuploadbuild lookups (60ms)
37 LFA lookups (50ms)
37 DistributionSourcePackage lookups (50ms)
30 assignee lookups (122ms)
30 bugsubscription lookups (70ms)
27 team membership lookups (120ms)
24 structuralsubscription lookups (2300ms)
3 SourcePackageFilePublishing (700ms)

So while its terrible, the proximate cause is structural bug subscriptions combined with potato programming.

(by terrible I mean the page does >1000 queries, so its very noisy etc)

This affects copies too, eg. OOPS-1956CH112

It's back. (Error ID: OOPS-2004CQ13)

Not sure which bug I'm supposed to be adding these too, but got a timeout again today accepting 4 binaries (worked on the second try):

(Error ID: OOPS-2062CC88)

(Error ID: OOPS-2084E90)

Failed with ten packages at once. Two sets of five worked.

I've added the:

  https://launchpad.net/ubuntu/oneiric/+queue?queue_state=3&queue_text=&direction=backwards&start=65340

URL to the top of this bug (from my dup), which consistently shows the issue.

Paul, thats a totally different issue. Please don't mangle bugs like that.

Roberts: Thanks for unduping it (I was not the one that duped it).

On Fri, Sep 16, 2011 at 1:05 PM, Paul Sladen <email address hidden> wrote:
> Roberts: Thanks for unduping it (I was not the one that duped it).

No problem - sorry for being harsh in my initial reply, that was
before I had noticed the source of the confusion.

On Friday 16 September 2011 02:05:42 you wrote:
> Roberts: Thanks for unduping it (I was not the one that duped it).

It was me.

One of the reasons I did it is because that page needs throwing away and re-
doing. It's an abomination of the highest order and is full of hacks and
workarounds to mitigate the original code that was even more worse at timing
out. Any fixes made to the existing page is just turd polishing.

Encountering this again as we're processing unapproved queue for precise.

Also affected the PackageUpload.acceptFromQueue API today: OOPS-010486e682dfae5a2594aa81edcedc98

As previously mentioned, the main area this all goes horribly wrong is in closing bugs for the upload being accepted. OK, in the latest OOPS I posted there are 172 SQL statements and 1.4 seconds before that, which isn't great, but it would be tolerable on its own.

I spent a bit of time trying to make things generally faster, but that requires a much smarter Launchpad developer than I'm capable of playing on TV. The next obvious approach appears to be to add a new ProcessAcceptedBugsJob, which can run as part of the FREQUENT group (contingent on my fix for bug 839659) and which would basically do all the bug.setStatus and bug.newMessage stuff from close_bugs_for_sourcepackagerelease. This would therefore amount to moving the guts of that latter function into a new job, adding job wrapping around it, and changing a few other functions to get bug IDs rather than IBugs (since bug IDs are a bit easier to pass around in job metadata, and the code that got bug objects was unnecessary potato programming anyway). This actually seems quite straightforward. It would require a DB patch as follows to start with:

CREATE TABLE ProcessAcceptedBugsJob (
    id serial PRIMARY KEY,
    job integer REFERENCES Job ON DELETE CASCADE UNIQUE NOT NULL,
    distroseries integer REFERENCES DistroSeries,
    sourcepackagerelease integer REFERENCES SourcePackageRelease NOT NULL,
    json_data text
);

Does that look reasonable in principle?

r11843 in db-stable (http://bazaar.launchpad.net/~launchpad-pqm/launchpad/db-stable/revision/11843) is part of this bug's fix.

2012-08-22 07:08:28 INFO 2209-27-2 applied just now in 0.1 seconds

r15988 in stable (http://bazaar.launchpad.net/~launchpad-pqm/launchpad/stable/revision/15988) is part of this bug's fix.

The cron script and feature flag are now enabled on production, and all looks well so far. We'll monitor this through the current 12.10 beta-2 freeze, and if all is well then I'll close this bug by removing the feature flag.

Fixed in stable r16045 <http://bazaar.launchpad.net/~launchpad-pqm/launchpad/stable/revision/16045>.