Put this in your WSGI script file (wsgi.py).
import time
import threading
class Monitor(object):
initialized = False
lock = threading.Lock()
count = 0
@classmethod
def initialize(cls):
with Monitor.lock:
if not cls.initialized:
cls.initialized = True
cls.rollover()
@staticmethod
def rollover():
print('RUNNING GARBAGE COLLECTOR', time.time())
class Object(object):
pass
o1 = Object()
o2 = Object()
o1.o = o2
o2.o = o1
o1.t = Monitor()
del o1
del o2
def __del__(self):
global count
Monitor.count += 1
Monitor.rollover()
Monitor.initialize()
Then monitor the log file and see if it periodically outputs 'RUNNING GARBAGE
COLLECTOR' or whether it stops being output after a while.
Graham
On 16/02/2015, at 9:29 PM, Paul Royik <[email protected]> wrote:
> I'm sorry. Django 1.7.1
>
> On Monday, February 16, 2015 at 12:19:33 PM UTC+2, Graham Dumpleton wrote:
> I asked what version of Django are you running? Not Python.
>
> Graham
>
> On 16/02/2015, at 9:12 PM, Paul Royik <[email protected]> wrote:
>
> I'm using Python 2.7.9
> So, what solution do you propose?
>
> Is there any way to kill a thread? Because things now are working worse than
> wih unstoppable thread. I'm hitting request-timeout.
> Also memory grows on every request.
> Maybe there is way to kill thread on external calculations?
>
> On Monday, February 16, 2015 at 12:04:23 PM UTC+2, Graham Dumpleton wrote:
> What version of Django are you running? Older Django versions have a bug in
> them which can cause the Python garbage collector to block and no longer run.
> Memory usage will go up because Python objects are not reclaimed properly.
> Not out of the question that other third party libraries could cause this
> also and can see a correlation between it and the fact that you are hitting
> queue time where request threads are blocking on a thread mutex.
>
> The MaxRequestWorkers warning is because you ran out of capacity in the
> daemon processes due to all your long running requests and/or hung requests.
> The fact you are hitting the request timeout means that the daemon process
> likely has stopped taking more requests and eventually as new requests back
> up, the Apache child worker process eventually complain as they also run out
> of capacity in their capacity of proxying requests.
>
> So it is an outcome of the problems you are having. You still need to work
> out the underlying problem.
>
> Graham
>
> On 16/02/2015, at 8:53 PM, Paul Royik <[email protected]> wrote:
>
> I also got following error.
> server reached MaxRequestWorkers setting, consider raising the
> MaxRequestWorkers setting
>
> On Sunday, February 15, 2015 at 10:42:19 PM UTC+2, Paul Royik wrote:
> As I discovered, memory grows on every request, not only calculator, even in
> admin. Situation is very close to this:
> http://stackoverflow.com/questions/2293333/django-memory-usage-going-up-with-every-request
> I hit 3 GB. It is the first time.
>
> On Sunday, February 15, 2015 at 1:59:06 PM UTC+2, Paul Royik wrote:
> It grows. Below is list between subsequent requests.
> 78988
> 85503
> 92873
> 100237
>
> On Sunday, February 15, 2015 at 1:36:15 PM UTC+2, Graham Dumpleton wrote:
> It being empty is fine.
>
> At least is not caused by uncollectable objects.
>
> Next would be to trying printing out periodically:
>
> len(gc.get_objects())
>
> and see if it grows over time.
>
> This is not conclusive either as meaning anything, but if it does keep
> growing, still useful to know.
>
> Graham
>
> On 15/02/2015, at 10:32 PM, Paul Royik <[email protected]> wrote:
>
> Don't know why but gc.garbage is empty list.
>
> On Sunday, February 15, 2015 at 1:04:15 PM UTC+2, Graham Dumpleton wrote:
> If the objects cannot be reclaimed due to Python objects cycles where objects
> have __del__() methods, they simply are not able to be reclaimed.
>
> You can try:
>
> import gc
> gc.collect()
>
> but will likely have little effect.
>
> I would suggest you also read:
>
> http://christian.hofstaedtler.name/blog/2013/01/gc-garbage.html
>
> Graham
>
> On 15/02/2015, at 10:00 PM, Paul Royik <[email protected]> wrote:
>
> Can I force cleaning memory after algorithm has finished?
>
> On Sunday, February 15, 2015 at 12:53:30 PM UTC+2, Graham Dumpleton wrote:
>
> On 15/02/2015, at 9:41 PM, Paul Royik <[email protected]> wrote:
>
> I reduced possibility by restricting very long and complex expressions.
>
> Code, that I use is simple.
>
> class TimeLimit(object):
> def __init__(self, timeout=60):
> self.timeout = timeout
> self.end = None
>
> def check_timeout(self):
> if self.end and time.time() > self.end:
> raise TimeoutException
> else:
> self.start()
>
> def start(self):
> if not self.end:
> self.end = time.time() + self.timeout
>
> class MainClass(object):
> def __init__(self):
> self.timer = TimeLimit()
> algo(timer)
>
>
> def algo(timer):
> do_something()
> external()
> timer.check_timeout()
> algo(timer)
>
> Which ultimately is no different to what was being done with the decorator.
>
> If external() can run a lot longer than the timeout, either way is not going
> to be much use. It is only going to be of much use if external() is always a
> short call and on subsequent calls you are simply calling it with different
> arguments.
>
> I debugged code thoroughly and it works as expected. And as shown memory is
> not drastically increased during execution, but later. Is that possible that
> reasong in apache conf? Or I need to look for problem in code? I have no clue
> where to search as everything works. Is it possible to see memory usage
> somehow on localhost (I'm under Windows)?
>
> It is unlikely to be the Apache configuration. It is more likely that after
> finishing the execution of the algorithm, the algorithm isn't clearing out
> any working data structures it creates when it is doing calculations and they
> are persisting in memory. Subsequent calls simply add more memory each time
> and so it grows in that way.
>
> There are various reasons that Python objects cannot be reclaimed and will
> keep using memory.
>
> There aren't really great tools for tracking that sort of stuff down.
>
> Graham
>
> On Sunday, February 15, 2015 at 12:31:36 PM UTC+2, Graham Dumpleton wrote:
>
> On 15/02/2015, at 9:26 PM, Paul Royik <[email protected]> wrote:
>
> Yes. External library could run long (although I reduced this possibility).
>
> How have you reduced possibility?
>
> So, what should I do with locking threads? Is it resolvable?
>
> No idea. It isn't my code. I can only highlight what looks suspicious in the
> log output.
>
> I'm just now playing with code on stackoverflow. People suggested to create
> class instead of decorator and pass its instance in all functions. I did as
> they proposed and it worked.
>
> Since you don't provide the code for that, I can't comment.
>
> However, with the flow of time I see increase in memory.
> So, now nobody access site.
>
> I ran command ps -u simamura -o pid,rss,command | awk '{print $0}{sum+=$2}
> END {print "Total", sum/1024, "MB"}' and see 200 MB.
> Then I invoke integral calculator, while it works above command shows 200 MB.
> Calculator finished, I check memory - still 200 MB. In 10-15 minutes
> (remember nobody access the site) I see 240 MB.
>
> In result, memory increased from 130 MB (memory immediately after server
> restart) to 435 MB in 10 hours.
>
> How can I resolve this issue? I feel that in another 12 hours webfaction will
> kill the process, because I memomy will be over limit.
>
> Have you tried adding print() debug statements to your code to track through
> what is being called and to determine whether your code is doing what is
> expected?
>
> Graham
>
> On Sunday, February 15, 2015 at 12:12:39 PM UTC+2, Graham Dumpleton wrote:
>
> On 15/02/2015, at 9:03 PM, Paul Royik <[email protected]> wrote:
>
> How do you know that it runs too long?
>
> In explained the log output previously and what was happening.
>
> If you go back far enough in the logs even before what you provided you will
> see some messages like:
>
> [Fri Feb 06 12:39:06.254056 2015] [wsgi:info] [pid 9731:tid 140178879313664]
> mod_wsgi (pid=9731): Daemon process request time limit exceeded, stopping
> process 'localhost:20241'.
> [Fri Feb 06 12:39:06.254108 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): Shutdown requested 'localhost:20241'.
> [Fri Feb 06 12:39:06.286339 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): Dumping stack trace for active Python threads.
> [Fri Feb 06 12:39:06.286359 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): Thread 140178316318464 executing file
> "/usr/local/lib/python2.7/threading.py", line 147, in acquire
> [Fri Feb 06 12:39:06.286363 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): called from file
> "/home/simamura/lib/python2.7/sympy/core/compatibility.py", line 851, in
> wrapper,
> [Fri Feb 06 12:39:06.286366 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): called from file
> "/home/simamura/lib/python2.7/sympy/core/cache.py", line 89, in wrapper,
> [Fri Feb 06 12:39:06.286369 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): called from file
> "/home/simamura/lib/python2.7/sympy/core/operations.py", line 127, in
> _matches_commutative,
> [Fri Feb 06 12:39:06.286372 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): called from file
> "/home/simamura/lib/python2.7/sympy/core/mul.py", line 808, in matches,
> [Fri Feb 06 12:39:06.286375 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): called from file
> "/home/simamura/lib/python2.7/sympy/core/add.py", line 358, in
> _matches_simple,
> [Fri Feb 06 12:39:06.286378 2015] [wsgi:info] [pid 9731:tid 140179136616192]
> mod_wsgi (pid=9731): called from file
> "/home/simamura/lib/python2.7/sympy/core/operations.py", line 127, in
> _matches_commutative,
>
> So it says that request time limit was exceeded.
>
> This is followed by stack dumps for what all the request threads were doing.
>
> In the part you did show, they both are stuck in:
>
> [Sat Feb 14 19:58:00.261118 2015] [wsgi:info] [pid 12528:tid 139862016030464]
> mod_wsgi (pid=12528): Thread 139861715523328 executing file
> "/usr/local/lib/python2.7/threading.py", line 147, in acquire
> [Sat Feb 14 19:58:00.261120 2015] [wsgi:info] [pid 12528:tid 139862016030464]
> mod_wsgi (pid=12528): called from file
> "/home/simamura/lib/python2.7/sympy/core/compatibility.py", line 851, in
> wrapper,
> [Sat Feb 14 19:58:00.261122 2015] [wsgi:info] [pid 12528:tid 139862016030464]
> mod_wsgi (pid=12528): called from file
> "/home/simamura/lib/python2.7/sympy/core/cache.py", line 89, in wrapper,
> [Sat Feb 14 19:58:00.261125 2015] [wsgi:info] [pid 12528:tid 139862016030464]
> mod_wsgi (pid=12528): called from file
> "/home/simamura/lib/python2.7/sympy/core/mul.py", line 373, in _gather,
> [Sat Feb 14 19:58:00.261127 2015] [wsgi:info] [pid 12528:tid 139862016030464]
> mod_wsgi (pid=12528): called from file
> "/home/simamura/lib/python2.7/sympy/core/mul.py", line 98, in flatten,
>
> That is, they are both waiting on a thread lock.
>
> This suggests to me that the code isn't possibly dealing with locking
> properly, or a lock is held for a very long time while in some certain
> section and blocking other threads from running and so why they are delayed
> and take so long.
>
> No more than 300 seconds as I wrote in conf file (socket-timeout and
> request-timeout).
>
> I can not control it thoroughly.
> def algo():
> do_something()
> invoke_external_library() # this could run slighlty longer, so timeout is
> not precise
> check_timeout()
> algo()
>
> So the thing that takes the unpredictable amount of time and you need to
> interrupt is not even your code?
>
> Graham
>
> On Sunday, February 15, 2015 at 11:36:05 AM UTC+2, Graham Dumpleton wrote:
> So we are back the fact that your requests are still running too long and
> however you have set up the timeout check isn't working.
>
> Have you added print() debug statements in your code to validate that the die
> on timeout check is even being run regularly?
>
> To be able to distinguish each request thread, you can include the output of
> threading.currentThread() on the print statements.
>
> Graham
>
> On 15/02/2015, at 8:19 PM, Paul Royik <[email protected]> wrote:
>
> [Sat Feb 14 19:58:00.261309 2015] [wsgi:info] [pid 12528:tid 139862016030464]
> mod_wsgi (pid=12528): called from file
> "/home/simamura/lib/python2.7/mod_wsgi/server/__init__.py", line 1137, in
> handle_request.
> [Sat Feb 14 19:58:05.245850 2015] [wsgi:info] [pid 12528:tid 139861541500672]
> mod_wsgi (pid=12528): Aborting process 'localhost:20241'.
> [Sat Feb 14 19:58:05.245889 2015] [wsgi:info] [pid 12528:tid 139861541500672]
> mod_wsgi (pid=12528): Exiting process 'localhost:20241'.
> [Sun Feb 15 01:58:05.352861 2015] [wsgi:error] [pid 11272:tid
> 139862014424832] [client 127.0.0.1:48193] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.352890 2015] [wsgi:error] [pid 11272:tid
> 139862015223552] [client 127.0.0.1:48563] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.352958 2015] [wsgi:error] [pid 11272:tid
> 139861948524288] [client 127.0.0.1:48240] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.352992 2015] [wsgi:error] [pid 11272:tid
> 139862015489792] [client 127.0.0.1:48440] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.353008 2015] [wsgi:error] [pid 11666:tid
> 139862014957312] [client 127.0.0.1:48329] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.353015 2015] [wsgi:error] [pid 11272:tid
> 139862014691072] [client 127.0.0.1:48620] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.353081 2015] [wsgi:error] [pid 11272:tid
> 139861949323008] [client 127.0.0.1:48778] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.353081 2015] [wsgi:error] [pid 11666:tid
> 139861948790528] [client 127.0.0.1:48735] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.353096 2015] [wsgi:error] [pid 11666:tid
> 139862015223552] [client 127.0.0.1:48792] Truncated or oversized response
> headers received from daemon process 'localhost:20241':
> /home/simamura/webapps/django_math/express/htdocs/calculators, referer:
> http://www.emathhelp.net/calculators/calculus-2/integral-calculator/
> [Sun Feb 15 01:58:05.972993 2015] [wsgi:info] [pid 24792:tid 139862016030464]
> mod_wsgi (pid=12528): Process 'localhost:20241' has died, deregister and
> restart it.
> [Sun Feb 15 01:58:06.081051 2015] [wsgi:info] [pid 24792:tid 139862016030464]
> mod_wsgi (pid=12528): Process 'localhost:20241' has been deregistered and
> will no longer be monitored.
> [Sun Feb 15 01:58:06.081333 2015] [wsgi:info] [pid 23028:tid 139862016030464]
> mod_wsgi (pid=23028): Starting process 'localhost:20241' with threads=10.
> [Sun Feb 15 01:58:06.163910 2015] [wsgi:info] [pid 23028:tid 139862016030464]
> mod_wsgi (pid=23028): Python home /usr/local.
> [Sun Feb 15 01:58:06.163937 2015] [wsgi:info] [pid 23028:tid 139862016030464]
> mod_wsgi (pid=23028): Initializing Python.
> [Sun Feb 15 01:58:06.534740 2015] [wsgi:info] [pid 23028:tid 139862016030464]
> mod_wsgi (pid=23028): Attach interpreter ''.
> [Sun Feb 15 01:58:06.549849 2015] [wsgi:info] [pid 23028:tid 139862016030464]
> mod_wsgi (pid=23028): Imported 'mod_wsgi'.
> [Sun Feb 15 01:58:06.549942 2015] [wsgi:info] [pid 23028:tid 139862016030464]
> mod_wsgi (pid=23028, process='localhost:20241', application=''): Loading WSGI
> script '/home/simamura/webapps/django_math/express/handler.wsgi'.
> [Sun Feb 15 02:06:36.476939 2015] [core:info] [pid 11272:tid 139861948524288]
> [client 127.0.0.1:56156] AH00128: File does not exist:
> /home/simamura/webapps/math_root/browserconfig.xml
>
>
> And that's all.
>
> On Sunday, February 15, 2015 at 10:11:25 AM UTC+2, Graham Dumpleton wrote:
> Provide me with the logging from a period before the restart until a period
> after.
>
> The log can be very informative if you know what to look for.
>
> Graham
>
> On 15/02/2015, at 6:43 PM, Paul Royik <[email protected]> wrote:
>
> I actually have custom error 500 page. This means, that when Django throws
> error, custom page should be shown.
> But it is not the case. Standard white-background apache page is shown.
> So, I think that problem is not in Django exception. Otherwise Django would
> show custom page, which is not the case.
> In logs I saw only that server was restarted.
> Can I somehow tune logging, so that real error is written?
>
> On Sunday, February 15, 2015 at 2:44:50 AM UTC+2, Graham Dumpleton wrote:
>
> On 15/02/2015, at 10:53 AM, Paul Royik <[email protected]> wrote:
>
> > I already tried this approach.
> >
> > It seems good.
> > But when I tested it on server, by simultaneously executing page on two
> > different computers, it gave me 500 error.
> >
> > How this can be explained? Again something with apache? Logs didn't show
> > anything. But I noticed again serious memory usage. And this happens only
> > when I use code for limiting time.
>
>
> Some tips for you about ensuring you get the best help.
>
> Stop discarding the message content for the message you are replying to. It
> can be frustrating to have to keep going back to old messages to see what was
> said originally and what you may be following up to, especially when on a
> phone. When asking questions on mailing list, let the person you are asking
> questions of decide what can be discarded from the message chain as they will
> know better what should be kept in the message to provide easy access to
> important information for context.
>
> When you reply to say you are have a new error, provide the actual code you
> were using exactly at the time you had the error. Saves the person who is
> helping you having to go back and ask for it if it is unclear what code you
> were using.
>
> Your messages here and on StackOverflow show that you play around with the
> example code I am giving you and I have reduced confidence you were running
> with the code I suggested at the time of the problem you are now relating to.
>
> If you are getting 500 errors and nothing is being logged, it is because
> Django is capturing the exception and converting it to a generic 500 error
> response page. Configure Django to send you emails with the details of the
> exceptions. If you are on a local system, then set DEBUG=True in the Django
> settings so the details of the error are shown in response that goes back to
> the browser.
>
> As to the code, I did test it this time, including under mod_wsgi with 20
> request threads and hitting it with concurrent and successive requests with a
> benchmarking tool. I saw no issues and it appeared to behave as I would
> expect.
>
> So in a test2.py file I had:
>
> import time
> import functools
> import threading
>
> def time_limit(seconds):
> def decorator(func):
> func.info = threading.local()
> def check_timeout():
> if time.time() > func.info.end_time:
> raise RuntimeError('timeout')
>
> func.check_timeout = check_timeout
>
> @functools.wraps(func)
> def wrapper(*args, **kwargs):
> print 'hasattr counter', hasattr(func.info, 'counter')
> if not hasattr(func.info, 'counter'):
> print 'init counter to 0'
> func.info.counter = 0
> if func.info.counter == 0:
> func.info.end_time = time.time() + seconds
> print 'counter', func.info.counter
> func.info.counter += 1
> try:
> return func(*args, **kwargs)
> finally:
> func.info.counter -= 1
>
> return wrapper
>
> return decorator
>
> @time_limit(5)
> def algorithm(limit, nest=0):
> algorithm.check_timeout()
> print 'sleep'
> time.sleep(1.0)
> if nest == limit:
> print 'return'
> return
> algorithm(limit, nest+1)
>
> In serial2.py I had a straight serialised test:
>
> from test2 import algorithm
>
> try:
> algorithm(3)
> except RuntimeError:
> print 'timeout'
>
> try:
> algorithm(10)
> except RuntimeError:
> print 'timeout'
>
> try:
> algorithm(10)
> except RuntimeError:
> print 'timeout'
>
> And then in hello2.wsgi I had it used by a WSGI application.
>
> from test2 import algorithm
>
> def application(environ, start_response):
> status = '200 OK'
> output = b'Hello World!'
>
> algorithm(1)
>
> response_headers = [('Content-type', 'text/plain'),
> ('Content-Length', str(len(output)))]
> start_response(status, response_headers)
>
> return [output]
>
> In the latter case I ran mod_wsgi-express against it as:
>
> mod_wsgi-express start-server hello2.wsgi --port 8002 --threads=20
>
> and then hit it with ab as:
>
> ab -n 100 -c 15 http://localhost:8002/
>
> In this case it wasn't designed to timeout anything, but that should not be a
> concern as the counter initialisation is still being tested.
>
> Do note that if you did cut and paste that last code, I did change the
> exception type.
>
> Anyway, the best thing to do is setup Django so that it provides the details
> of the exception it captured but then effectively discarded
> ...
>
> --
> You received this message because you are subscribed to the Google Groups
> "modwsgi" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to [email protected].
> To post to this group, send email to [email protected].
> Visit this group at http://groups.google.com/group/modwsgi.
> For more options, visit https://groups.google.com/d/optout.
--
You received this message because you are subscribed to the Google Groups
"modwsgi" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To post to this group, send email to [email protected].
Visit this group at http://groups.google.com/group/modwsgi.
For more options, visit https://groups.google.com/d/optout.
