736110 - Add logging in django-mysql-pool to exceptions raised by connection.ping()

Status: RESOLVED FIXED

(addons.mozilla.org Graveyard :: Code Quality, defect)

Description

[Kumar McMillan [:kumar]]

The pool uses connection.ping() to decide if it can re-use a connection. In bug 734922 there is a reproducible case where Django's connection.ping() raises an exception, ignores it, and closes the connection. This causes all other queries to fail.

We should override the ping and add logging to find out what that exception is.

Django code to override: https://github.com/django/django/blob/16e3c6e9a6c882a0a636506d8bd605e89e8851a6/django/db/backends/mysql/base.py#L351

Comment 1

[Kumar McMillan [:kumar]]

Meaty details of bug 734922 are here https://bugzilla.mozilla.org/show_bug.cgi?id=734922#c21

Comment 2

[Andy McKay]

Added some comments to bug 734922 and removed the log code. I think the log code shouldn't be logging the database name unless its connected, which might be a vicious loop. Perhaps just logging the db name isn't that smart :)

The django connection.ping catches the DatabaseError, because if the database isn't there, you'll get a database error which is rather sad and generic. Ideally somewhere down in the database adaptor there should be more specific DatabaseNotThereError that we can catch.

Comment 3

[Kumar McMillan [:kumar]]

mcdavis, could you try uploading your addon jar again? We just deployed a change that hopefully lets the database pool regenerate the connection properly.

Comment 4

[mcdavis941 (sporadically reading bugmail)]

(In reply to Kumar McMillan [:kumar] from comment #3)
> mcdavis, could you try uploading your addon jar again? We just deployed a
> change that hopefully lets the database pool regenerate the connection
> properly.

Sure.  I just tried and it looks like an improvement (no longer getting server status 500) but it hung somewhere during validation.  See the screenshot; it got that far then went no farher.  I let it sit there for 20 to 30 minutes but that's as far as it got.  I tried a second time a few minutes later with the same result.

Comment 5

[mcdavis941 (sporadically reading bugmail)]

Attachment: screenshot

Comment 6

[mcdavis941 (sporadically reading bugmail)]

(In reply to mcdavis941 (sporadically reading bugmail) from comment #4)
> I just tried and it looks like an improvement (no longer getting
> server status 500) but it hung somewhere during validation.

FYI, I just tried again with the same result (reaches validation step then hangs during validation) but from other bugs it looks like there may be other issues with the cluster at the moment which are unrelated to this bug.

Comment 7

[mcdavis941 (sporadically reading bugmail)]

I waited this week until it looked like most of the celery issues were taken care of, take save cycles for all of us, before coming back to this.  So I tried again three times this morning (or maybe yesterday, it was a big day and I can't remember now) and all of those failed with server errors reported in the upload panel like we've being seeing all along.

This evening I tried again and had one success surrounded by failures both before and after.  The one success did result in the new version showing in the list of versions for the add-on.  The screenshot represents this evening's attempts.

(I don't have a need to upload anything at this point .. just seeing if the logging shows anything illuminating.)

Comment 8

[mcdavis941 (sporadically reading bugmail)]

Attachment: screenshot 2012-03-31

Comment 9

[Kumar McMillan [:kumar]]

I created this bug as a reminder to fix the logging issue. That landed in https://github.com/andymckay/django-mysql-pool/commit/ce4883f68c402b7c9375fc37c360e428c0ab76b7

mcdavis, feel free to file a new bug if you run into problems