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 because >> it converted it to a 500 page. >> >> >> >> -- >> 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. >> >> >> >> -- >> 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 unsubscrib >> >> ... > > -- 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.
