Mysql sleeping queries

150 views
Skip to first unread message

David Reynolds

unread,
Jun 19, 2007, 1:51:22 AM6/19/07
to Django users
Morning,

We are experiencing a problem with Mysql with django. Since an svn
up yesterday (which seems to be revision 5492) we have lots of
sleeping (hanging) mysql processes and we keep hitting our limit of
processes (which we weren't doing before). Anyone have any idea why
it may be doing this?

Versions:

apache 2.0.54
mysql 4.0.24
mysqldb 1.2.1c2-1

If anyone can shed any light, I'd be very interested to know.

Thanks,

David

--
David Reynolds
da...@reynoldsfamily.org.uk


Gábor Farkas

unread,
Jun 19, 2007, 1:56:45 AM6/19/07
to django...@googlegroups.com
David Reynolds wrote:
> Morning,
>
> We are experiencing a problem with Mysql with django. Since an svn up
> yesterday (which seems to be revision 5492) we have lots of sleeping
> (hanging) mysql processes and we keep hitting our limit of processes
> (which we weren't doing before). Anyone have any idea why it may be
> doing this?
>
> Versions:
>
> apache 2.0.54
> mysql 4.0.24
> mysqldb 1.2.1c2-1
>
> If anyone can shed any light, I'd be very interested to know.
>

hi,

i have no idea what went wrong, but to the developers it certainly would
help, if you could find out exactly which revision broke the mysql
behaviour.

gabor

David Reynolds

unread,
Jun 19, 2007, 2:02:42 AM6/19/07
to django...@googlegroups.com

On 19 Jun 2007, at 6:56 am, Gábor Farkas wrote:

> hi,
>
> i have no idea what went wrong, but to the developers it certainly
> would
> help, if you could find out exactly which revision broke the mysql
> behaviour.

Difficult to tell since we hadn't svn up'd for a while...

--
David Reynolds
da...@reynoldsfamily.org.uk


Malcolm Tredinnick

unread,
Jun 19, 2007, 3:04:18 AM6/19/07
to django...@googlegroups.com
On Tue, 2007-06-19 at 07:02 +0100, David Reynolds wrote:
> On 19 Jun 2007, at 6:56 am, Gábor Farkas wrote:
>
> > hi,
> >
> > i have no idea what went wrong, but to the developers it certainly
> > would
> > help, if you could find out exactly which revision broke the mysql
> > behaviour.
>
> Difficult to tell since we hadn't svn up'd for a while...

The usual process would be to note the version you are at now and take a
guess at an earlier version that worked (trial and error will do, if
nothing else). "svn up" to the earlier version, check it works. Then
split the difference and "svn up" to the version number in the middle,
check if it works. If it does, move forwards halfway. If not, move back
halfway. Rinse. Wash. Repeat.

Regards,
Malcolm

Malcolm Tredinnick

unread,
Jun 19, 2007, 3:09:30 AM6/19/07
to django...@googlegroups.com
On Tue, 2007-06-19 at 06:51 +0100, David Reynolds wrote:
> Morning,
>
> We are experiencing a problem with Mysql with django. Since an svn
> up yesterday (which seems to be revision 5492) we have lots of
> sleeping (hanging) mysql processes and we keep hitting our limit of
> processes (which we weren't doing before). Anyone have any idea why
> it may be doing this?
>
> Versions:
>
> apache 2.0.54
> mysql 4.0.24
> mysqldb 1.2.1c2-1
>
> If anyone can shed any light, I'd be very interested to know.

It would be interesting to know if anything prior to [5482] (that's
5482, not 5492) works. There was a very large change in [5482] that
should be mostly invisible but may have some side-effects we need to be
aware of.

The details, if you care: template output is now generated via
iterators, rather than constructing a huge string and passing the string
around. This should be mostly invisible. However, one thing that might
be observable is that functions which are called to generate the
template may not necessarily be called until the data is being sent back
to the client. Ticket #4612, for example, shows how this can be a bit
subtle in middleware (not actually a bug, just some experience gained).

Now, I have no idea if this is affecting you, but off the top of my
head, that is the biggest change we have pushed out lately. I can't
think of any MySQL specific changes, but I'm getting old and my memory
is failing sometimes, so maybe I've forgotten something.

Regards,
Malcolm

David Reynolds

unread,
Jun 19, 2007, 9:34:13 AM6/19/07
to django...@googlegroups.com
Malcolm,

On 19 Jun 2007, at 8:09 am, Malcolm Tredinnick wrote:

> It would be interesting to know if anything prior to [5482] (that's
> 5482, not 5492) works. There was a very large change in [5482] that
> should be mostly invisible but may have some side-effects we need
> to be
> aware of.

Thanks for your advice - I went back to 5481, which seems to have
cleared it up.

> The details, if you care: template output is now generated via
> iterators, rather than constructing a huge string and passing the
> string
> around. This should be mostly invisible. However, one thing that might
> be observable is that functions which are called to generate the
> template may not necessarily be called until the data is being sent
> back
> to the client. Ticket #4612, for example, shows how this can be a bit
> subtle in middleware (not actually a bug, just some experience
> gained).
>
> Now, I have no idea if this is affecting you, but off the top of my
> head, that is the biggest change we have pushed out lately. I can't
> think of any MySQL specific changes, but I'm getting old and my memory
> is failing sometimes, so maybe I've forgotten something.

I didn't mention that we were using mysql_old (although I guess that
was perhaps obvious from the version of MySQLdb). Having fixed the
sites we have running trunk (by going back to r5481) we have noticed
that the few sites we still have running pre-magic-removal also have
sleeping processes - is this normal? Is there anything we can do to
stop this?

Thanks for your help,

Gábor Farkas

unread,
Jun 19, 2007, 12:16:35 PM6/19/07
to django...@googlegroups.com
David Reynolds wrote:
> Malcolm,
>
> On 19 Jun 2007, at 8:09 am, Malcolm Tredinnick wrote:
>
>> It would be interesting to know if anything prior to [5482] (that's
>> 5482, not 5492) works. There was a very large change in [5482] that
>> should be mostly invisible but may have some side-effects we need to be
>> aware of.
>
> Thanks for your advice - I went back to 5481, which seems to have
> cleared it up.

i'm glad this fixed your problem, but please note that:

from the information you provided, we know that 5481 works, but 5492
does not. but this does not mean that 5481 broke it. there are still 10
revisions (starting with 5482 and ending with 5491) which might or might
not work.

so if you have the possibility, please try to investigate which exact
revision broke it for you.

a simple binary search would work, like..try the "version in the middle"
(5486). if works, then 5499, if does not work then 5484 etc.

gabor

David Reynolds

unread,
Jun 20, 2007, 10:39:45 AM6/20/07
to django...@googlegroups.com

On 19 Jun 2007, at 5:16 pm, Gábor Farkas wrote:
>
> i'm glad this fixed your problem, but please note that:
>
> from the information you provided, we know that 5481 works, but 5492
> does not. but this does not mean that 5481 broke it. there are
> still 10
> revisions (starting with 5482 and ending with 5491) which might or
> might
> not work.
>
> so if you have the possibility, please try to investigate which exact
> revision broke it for you.
>
> a simple binary search would work, like..try the "version in the
> middle"
> (5486). if works, then 5499, if does not work then 5484 etc.

We have done some testing and it does seem to appear in 5482, as
Malcolm suggested. 5481 is fine, 5482 starts the hanging mysql
processes.

Hope that helps,

Ilya Semenov

unread,
Jun 20, 2007, 2:36:22 PM6/20/07
to Django users
Malcolm,

I'm having exactly the same problem.
Under Apache+mod_python, each HTTP request keeps a stale MySQL
connection.

I traced the changeset, it was 5481->4582.

I put some logging to django.db.backends.mysql.base:

....
self.connection = Database.connect(**kwargs)
+ log.msg("connected to %s" % self.connection)
....
+ log.msg("closed %s" % self.connection)
self.connection.close()
....

The output was (for 2 HTTP requests):
2007/06/20 19:56 NOVST [-] Log opened.
2007/06/20 19:56 NOVST [-] connected to <_mysql.connection open to
'localhost' at 867f5ec>
2007/06/20 19:56 NOVST [-] closed <_mysql.connection open to
'localhost' at 867f5ec>
2007/06/20 19:56 NOVST [-] connected to <_mysql.connection open to
'localhost' at 86c8af4>
2007/06/20 19:56 NOVST [-] connected to <_mysql.connection open to
'localhost' at 87fa7dc>
2007/06/20 19:56 NOVST [-] closed <_mysql.connection open to
'localhost' at 87fa7dc>
2007/06/20 19:56 NOVST [-] connected to <_mysql.connection open to
'localhost' at 8829fe4>

You see, 2 connections are opened and only 1 is closed per request.

As the result, there were two sleeping stale MySQL connections (output
of SHOW PROCESSLIST)
| 907 | root | localhost | corp2 | Sleep | 5 | |
NULL |
| 909 | root | localhost | corp2 | Sleep | 2 | |
NULL |

(Note the IDs had a gap between them).

If you have no time and/or can't reproduce the problem, I will try to
trace further and hopefully come up with a patch.

Sean Mc Allister

unread,
Jun 20, 2007, 7:14:11 PM6/20/07
to django...@googlegroups.com
Just to let you know, I'm using postgres and I am also experiencing the
same problems with revisions above 5481.
It doesn't seem to leave every connection open, but more like 2 out of 3
or something like that. so it's not only a mysql thing.

Sean

Malcolm Tredinnick

unread,
Jun 20, 2007, 7:45:43 PM6/20/07
to django...@googlegroups.com
On Thu, 2007-06-21 at 01:14 +0200, Sean Mc Allister wrote:
> Just to let you know, I'm using postgres and I am also experiencing the
> same problems with revisions above 5481.
> It doesn't seem to leave every connection open, but more like 2 out of 3
> or something like that. so it's not only a mysql thing.

Okay, this is all good information.

Does it only happen when DEBUG=True, or at other times as well?

If I (or somebody else, even better) can't track down the solution
shortly, I'll roll back [5482] for a bit until we understand the
side-effects better. Will leave it for a day or so to give you guys time
to debug further, though.

Regards,
Malcolm


Malcolm Tredinnick

unread,
Jun 20, 2007, 9:06:14 PM6/20/07
to django...@googlegroups.com

I guess another relevant question here is how are people hooked up to
their webservers when you are seeing these problems? Is it happening
with mod_python, wsgi, fastcgi, dev server, ...?

Regards,
Malcolm

David Reynolds

unread,
Jun 21, 2007, 4:07:34 AM6/21/07
to django...@googlegroups.com

On 21 Jun 2007, at 2:06 am, Malcolm Tredinnick wrote:

> Okay, this is all good information.
>
> Does it only happen when DEBUG=True, or at other times as well?

Both. One of the things people in IRC suggested I check was whether
DEBUG was set to True. It happens in both cases for us.


> I guess another relevant question here is how are people hooked up to
> their webservers when you are seeing these problems? Is it happening
> with mod_python, wsgi, fastcgi, dev server, ...?

In our case we are using mod_python. Let me know if you need version
numbers or any other information.

Thanks,

Ilya Semenov

unread,
Jun 21, 2007, 10:45:36 AM6/21/07
to Django users
Malcolm,

I traced the problem and submitted the patch, see details at
http://code.djangoproject.com/ticket/4650
I'm not completely sure about the logic of signals though, the change
may affect some middleware depending on it.

Malcolm Tredinnick

unread,
Jun 21, 2007, 7:54:50 PM6/21/07
to django...@googlegroups.com

One other thing that I forgot in my earlier email: it's not actually
clear why the database connections get "lost" in the current
implementation. We close the connection too early, but when the template
rendering needs to access the database, it just opens a new one (that is
why everybody is seeing more opens than closes). However, the next time
that thread or process is used, Django should be reusing the same
connection, since it will still be open and we check for an existing
connection before opening a new one. So in a sufficiently robust test
(that reuses threads), I would have expected no lost connections. The
reason why people are seeing them is something I haven't quite tracked
down yet.

Malcolm


Malcolm Tredinnick

unread,
Jun 21, 2007, 7:52:34 PM6/21/07
to django...@googlegroups.com
On Thu, 2007-06-21 at 07:45 -0700, Ilya Semenov wrote:

Thanks, Ilya. I'd gotten that far, too. Unfortunately, though, it isn't
quite that easy. Well, it is that easy for mod_python, however for WSGI
compliance, we can't do that (since the WSGI handler returns an
iterable).

There are a few possibilities I've been bouncing around, but they all
have downsides: introducing greater coupling between templates, HTTP and
database so that we know when rendering stops (which will make it
possible to behave similarly to the modpython case) or making WSGI
return a single item iterable as recommended in PEP 333 for performance
(downside is that the greater part of the memory savings are lost).

For portability reasons, supporting WSGI is very important, so any
solution that only works with modpython is unfortunately not an option.

Regards,
Malcolm

Graham Dumpleton

unread,
Jun 21, 2007, 10:44:31 PM6/21/07
to Django users
On Jun 22, 9:52 am, Malcolm Tredinnick <malc...@pointy-stick.com>
wrote:

> On Thu, 2007-06-21 at 07:45 -0700, Ilya Semenov wrote:
> > Malcolm,
>
> > I traced the problem and submitted the patch, see details at
> >http://code.djangoproject.com/ticket/4650
> > I'm not completely sure about the logic of signals though, the change
> > may affect some middleware depending on it.
>
> Thanks, Ilya. I'd gotten that far, too. Unfortunately, though, it isn't
> quite that easy. Well, it is that easy formod_python, however for WSGI

> compliance, we can't do that (since the WSGI handler returns an
> iterable).
>
> There are a few possibilities I've been bouncing around, but they all
> have downsides: introducing greater coupling between templates, HTTP and
> database so that we know when rendering stops (which will make it
> possible to behave similarly to the modpython case) or making WSGI
> return a single item iterable as recommended in PEP 333 for performance
> (downside is that the greater part of the memory savings are lost).

Sorry, showing my ignorance here. Are you saying that Django can
currently return to the WSGI adapter for the web server a Python
string in some cases?

Looking at the submitted patch it almost seems that that is possible
in some cases, otherwise I don't understand the need for the check:

197 if isinstance(self._response, basestring):
198 return chain([self._response],
IterConsumedSignal)

I only ask as returning a string means that the WSGI adapter would
treat it as an array of single character strings and by the WSGI
specification the WSGI adapter is required to write each character out
one at a time and perform a flush between each character. If doing
this in Apache this would result in absolutely dreadful performance.

As it stands, this patch would actually change the behaviour of a WSGI
adapter in that the string would then be written out in one go and not
one character at a time as it would if just the string were passed
through. Another issue with this check is that it checks against
'basestring' whereas WSGI is only supposed to be given 'string'
objects. The check would allow through 'unicode' string objects.

Also, I am presuming 'chain' comes from itertools but don't see that
module being imported. Nor is it prefixed by the module name anyway.

BTW, why does one need to be using chain of iterables anyway. The WSGI
specification requires that a WSGI adapter call close() on the
iterable when it is done. Ie., quoting WSGI specification:

"""If the iterable returned by the application has a close() method,
the server or gateway must call that method upon completion of the
current request, whether the request was completed normally, or
terminated early due to an error. (This is to support resource release
by the application. This protocol is intended to complement PEP 325's
generator support, and other common iterables with close() methods."""

Thus, it wasn't necessary to introduce IterConsumedSignal at all.
Instead, if I understand what you are trying to do. The
ResponseWrapper could have provided its own close() method which
called response close() if it existed as well as call:

dispatcher.send(signal=signals.request_finished)

> For portability reasons, supporting WSGI is very important, so any
> solution that only works with modpython is unfortunately not an option.

Why was the patch only suitable for mod_python? I admit I don't
understand fully the underlying problem you are trying to solve, but
as far as satisfying WSGI specification, it seemed to be going in the
right direction.

Graham

Malcolm Tredinnick

unread,
Jun 21, 2007, 11:22:24 PM6/21/07
to django...@googlegroups.com
Hi Graham,

On Fri, 2007-06-22 at 02:44 +0000, Graham Dumpleton wrote:
> On Jun 22, 9:52 am, Malcolm Tredinnick <malc...@pointy-stick.com>
> wrote:
> > On Thu, 2007-06-21 at 07:45 -0700, Ilya Semenov wrote:
> > > Malcolm,
> >
> > > I traced the problem and submitted the patch, see details at
> > >http://code.djangoproject.com/ticket/4650
> > > I'm not completely sure about the logic of signals though, the change
> > > may affect some middleware depending on it.
> >
> > Thanks, Ilya. I'd gotten that far, too. Unfortunately, though, it isn't
> > quite that easy. Well, it is that easy formod_python, however for WSGI
> > compliance, we can't do that (since the WSGI handler returns an
> > iterable).
> >
> > There are a few possibilities I've been bouncing around, but they all
> > have downsides: introducing greater coupling between templates, HTTP and
> > database so that we know when rendering stops (which will make it
> > possible to behave similarly to the modpython case) or making WSGI
> > return a single item iterable as recommended in PEP 333 for performance
> > (downside is that the greater part of the memory savings are lost).
>
> Sorry, showing my ignorance here. Are you saying that Django can
> currently return to the WSGI adapter for the web server a Python
> string in some cases?

Not at all. That would be bad (as you note below). If the HttpResponse
class is created with a string, the __iter__ method returns that as a
single chunk (we iterate over the list [content], where "content" is the
string). This is set up in HttpResponse.__init__ so that the _container
attribute on the instance is always an iterable.

My comment above was referring to the fact that HttpResponse can also be
initialised with an iterator (usually a Template.iter_render() result
after [5482]) and will use that in the __iter__ method in that case. One
solution to the problems we are seeing would involve collecting all the
output from that iterator and then returning a new iterator that gave
back all the data in one go. The advantage of that approach is better
control over signalling when the request is finished and possibly
slightly better network performance due to larger chunks being available
to the WSGI server. The downside is larger memory usage, which was what
the original template rendering change was designed to alleviate.

> Looking at the submitted patch it almost seems that that is possible
> in some cases, otherwise I don't understand the need for the check:
>
> 197 if isinstance(self._response, basestring):
> 198 return chain([self._response],
> IterConsumedSignal)

Brian might just be being careful. It's relatively harmless.

> I only ask as returning a string means that the WSGI adapter would
> treat it as an array of single character strings and by the WSGI
> specification the WSGI adapter is required to write each character out
> one at a time and perform a flush between each character. If doing
> this in Apache this would result in absolutely dreadful performance.

Yep. Understood. Fear not; we've haven't made a design decision to bring
the web server to its knees on every response. :-)

> As it stands, this patch would actually change the behaviour of a WSGI
> adapter in that the string would then be written out in one go and not
> one character at a time as it would if just the string were passed
> through.

Technically, yes; unfortunately implemented adaptors will no longer
behave badly. However, it's going to be used with Django's HttpResponse,
which doesn't iterate over strings one character at a time in the output
stream.

> Another issue with this check is that it checks against
> 'basestring' whereas WSGI is only supposed to be given 'string'
> objects. The check would allow through 'unicode' string objects.
>
> Also, I am presuming 'chain' comes from itertools but don't see that
> module being imported. Nor is it prefixed by the module name anyway.

Indeed. Both are problems. We'll fix those.

> BTW, why does one need to be using chain of iterables anyway. The WSGI
> specification requires that a WSGI adapter call close() on the
> iterable when it is done. Ie., quoting WSGI specification:

Yes. Brian (Harring -- the author of the second patch) also mentioned
this on the django-developers list shortly after he wrote the initial
patch. Sounds like the right thing to do.

[...]


> > For portability reasons, supporting WSGI is very important, so any
> > solution that only works with modpython is unfortunately not an option.
>
> Why was the patch only suitable for mod_python?

(Note that I was talking about Ilya's original patch; not Brian's
subsequent one with WSGI support.) With mod_python, we write the full
response content out before we return from Django's handler (see line
169 in django/core/handlers/modpython.py), so we know we have finished
all the database accesses necessary for template rendering. Thus we can
move the "request_finished" signal to the end of that method. Ilya's
patch is correct, but notice that it didn't address WSGI at all. That
was all my comment was about: we can't just fix one half of the problem.

An identical small change doesn't work for WSGI. In the WSGI handler, we
pass the iterator upstream and the database accesses will be triggered
when the iterator is consumed by the WSGI server. The wrapping in the
second patch is so that we can tell when the rendering has been
finished. The close() method is the better approach, though, you're
right.

> I admit I don't
> understand fully the underlying problem you are trying to solve,

For better or worse (I have opinions about this, not relevant to this
thread), we are using one database connection per request and closing it
upon completion. With the move to iterators and because template
rendering can require database accesses, we are currently needlessly
closing the database connection too early, which means a new one is
being opened during rendering and, for some reason, we are losing track
of it. Like i said in another post, I don't understand why the code
isn't automatically reusing it the next time that particular process or
thread is used and there is possibly some bullet-proofing in the backend
wrappers that is needed in addition to these changes, but I can't argue
with the evidence in this list thread.

Thanks for looking over this and asking the questions, anyway. It would
be nice if we were able to convince some onlookers that the approach
might work.

Regards,
Malcolm


Ivan Sagalaev

unread,
Jun 22, 2007, 2:01:20 AM6/22/07
to django...@googlegroups.com
Malcolm Tredinnick wrote:
> One other thing that I forgot in my earlier email: it's not actually
> clear why the database connections get "lost" in the current
> implementation. We close the connection too early, but when the template
> rendering needs to access the database, it just opens a new one (that is
> why everybody is seeing more opens than closes). However, the next time
> that thread or process is used, Django should be reusing the same
> connection, since it will still be open and we check for an existing
> connection before opening a new one.

In case of threads the old thread's connection can't be reused because
it is stored in thread.local() and a new thread is new thread. This
ad-hoc 'pooling' actually never worked AFAIR... And I suspect that at
least under Apache every new request results in a new Python thread both
with prefork and worker mpms.

Ivan Sagalaev

unread,
Jun 22, 2007, 2:05:04 AM6/22/07
to django...@googlegroups.com
Malcolm Tredinnick wrote:
> Thanks, Ilya. I'd gotten that far, too. Unfortunately, though, it isn't
> quite that easy. Well, it is that easy for mod_python, however for WSGI
> compliance, we can't do that (since the WSGI handler returns an
> iterable).

But a WSGI server calls "close()" on the iterator after iteration and we
support this in HttpResponse. Why not send "signals.request_finished" there?

Malcolm Tredinnick

unread,
Jun 22, 2007, 2:19:24 AM6/22/07
to django...@googlegroups.com

Perhaps read the remainder of the thread? :-)

Regards,
Malcolm


Ivan Sagalaev

unread,
Jun 22, 2007, 2:23:35 AM6/22/07
to django...@googlegroups.com
Malcolm Tredinnick wrote:
> Perhaps read the remainder of the thread? :-)

Sorry, I was too impatient this time :-)

Malcolm Tredinnick

unread,
Jun 22, 2007, 3:40:54 AM6/22/07
to django...@googlegroups.com
On Tue, 2007-06-19 at 06:51 +0100, David Reynolds wrote:
> Morning,
>
> We are experiencing a problem with Mysql with django. Since an svn
> up yesterday (which seems to be revision 5492) we have lots of
> sleeping (hanging) mysql processes and we keep hitting our limit of
> processes (which we weren't doing before). Anyone have any idea why
> it may be doing this?

One (hopefully) final update to this thread. After a fair bit of
discussion here and on the developer's list, we've pulled the changes
that were causing these problems out of the code. So if everybody who
was seeing the problems wants to update to [5511], things should be back
to normal.

Apologies for the length of the threads involved and thanks to everybody
who has worked on diagnosing, understanding and solving the problems so
far. This is why we like people testing trunk.

Regards,
Malcolm

Reply all
Reply to author
Forward
0 new messages