Debugging Live Python Web Applications

Monitoring tools record the result of what happened to your web application when a problem arises, but for some classes of problems, monitoring systems are only a starting point. Sometimes it is necessary to take more intrusive steps to plan for the unexpected by embedding mechanisms that will allow you to interact with a live deployed web application and extract even more detailed information.

1. Debugging Live Python Web Applications Amjith Ramanujam / Graham Dumpleton DjangoCon US - Sep 2012 Tuesday, September 4, 12
2. Follow along. http://www.speakerdeck.com/u/amjith Tuesday, September 4, 12
3. Overview • Scenario • Monitoring • Analysis • Live Debugging • ispyd Tuesday, September 4, 12
4. Why Debug? Tuesday, September 4, 12
5. Common Problems • Obvious - Python exception and traceback • Subtle - Mem leak, Thread locking, Data corruption • Performance - Site is slow! • Heisen - Shows up only in production. Tuesday, September 4, 12
6. Developers Tuesday, September 4, 12
7. DEVOPS Tuesday, September 4, 12
8. Things to avoid Tuesday, September 4, 12
9. Things to avoid. • Crashing the whole web site. • Corrupt all your customer data. • Make you customer data visible to everyone. • Lose your company lots of money. Tuesday, September 4, 12
10. Things to avoid Tuesday, September 4, 12
11. Managing risk. • Use software to restrict what you can do. • Script changes and procedures to avoid errors. • Test what you are going to do on a separate system. • Develop and document contingency plans. Tuesday, September 4, 12
12. Monitoring Tuesday, September 4, 12
13. Passive monitoring. • Collection of log file information. • Collection of details about Python exceptions. • Collection of performance data for the server host. • Collection of performance data for the web server. • Collection of performance data for the web application. Tuesday, September 4, 12
14. Log file collation and analysis. • Open Source • logstash (http://logstash.net) • graylog2 (http://www.graylog2.org) • Commercial Services • Loggly (http://www.loggly.com) • Splunk (http://www.splunk.com) • LogLogic (http://www/loglogic.com) Tuesday, September 4, 12
15. Recording Python exceptions. • Open Source • Sentry (http://pypi.python.org/pypi/sentry) • Commercial Services • New Relic (http://newrelic.com) Tuesday, September 4, 12
16. Server monitoring. • Open Source • Monit (http://mmonit.com) • Munin (http://munin-monitoring.org) • Cacti (http://www.cacti.net) • Nagios (http://www.nagios.org) • Commercial Services • New Relic (http://newrelic.com) - Free Tuesday, September 4, 12
17. Application performance monitoring. • Commercial Services • New Relic (http://newrelic.com) - Lite (Free), Standard and Pro subscriptions. Tuesday, September 4, 12
18. Your web site is slow. Tuesday, September 4, 12
19. Analysis Tuesday, September 4, 12
20. Web page performance analysis. • Online services. • YSlow (http://developer.yahoo.com/yslow/) • GooglePageSpeed (https://developers.google.com/speed/pagespeed/) • WebPageTest (http://www.webpagetest.org/) • Browser plugins. • YSlow (https://addons.mozilla.org/en-US/firefox/addon/yslow/) • FireBug (http://getfirebug.com/) Tuesday, September 4, 12
21. Application performance analysis. Tuesday, September 4, 12
22. Slow transaction summary. Tuesday, September 4, 12
23. Slow transaction details. Tuesday, September 4, 12
24. Unknown consumers of time. ???? ???? Tuesday, September 4, 12
25. Instrumentation via code change. import newrelic.agent @newrelic.agent.function_trace() def open(file, flag=None, mode=0666): ... Tuesday, September 4, 12
26. Instrumentation via configuration. [newrelic] transaction_tracer.function_trace = awesome_dbm:open awesome_dbm:_Database._commit Tuesday, September 4, 12
27. Instrumentation by monkey patching. #config [import-hook:awesome_dbm] enabled = true execute = awesome_dbm_instrumentation:instrument Tuesday, September 4, 12
28. Instrumentation by monkey patching. # awesome_dbm_instrument.py from newrelic.api.function_trace import \ wrap_function_trace def instrument(module): wrap_function_trace(module, 'open') wrap_function_trace(module, '_Database._commit') #config [import-hook:awesome_dbm] enabled = true execute = awesome_dbm_instrumentation:instrument Tuesday, September 4, 12
29. Profiling tools. • Thread sampling. • plop (http://tech.dropbox.com/?p=272) • statprof (http://pypi.python.org/pypi/statprof/) • Full profiling. • cprofile (http://docs.python.org/library/profile.html) • pytrace (http://pypi.python.org/pypi/pytrace) Tuesday, September 4, 12
30. Manual metric collection. • Open Source • metrology - http://metrology.readthedocs.org/en/latest/index.html • mmstats - https://github.com/schmichael/mmstats • pymetrics - https://github.com/jgardner1/Python-Metrics • django-app-metrics - http://pypi.python.org/pypi/django-app-metrics • django-statsd - http://django-statsd.readthedocs.org/en/latest/ Tuesday, September 4, 12
31. Interacting via the browser. • Open Source • Paste Error Middleware • Django-debug-toolbar • Paste Debugger • Flask Debugger Tuesday, September 4, 12
32. Live Debugging (Dark Art) Tuesday, September 4, 12
33. Application backdoors. import logging.config logging.config.fileConfig("logging.conf") backdoor = logging.config.listen() backdoor.start() Tuesday, September 4, 12
34. Interactive access. • Embedded interpreter prompt • eventlet.backdoor - http://eventlet.net/doc/modules/backdoor.html • guppy.heapy.Console - http://guppy-pe.sourceforge.net • twisted.manhole - http://www.lothar.com/tech/twisted/manhole.xhtml Tuesday, September 4, 12
35. Interactive access. • Embedded interpreter prompt • eventlet.backdoor - http://eventlet.net/doc/modules/backdoor.html • guppy.heapy.Console - http://guppy-pe.sourceforge.net • twisted.manhole - http://www.lothar.com/tech/twisted/manhole.xhtml • Code injection • pyrasite - http://pyrasite.readthedocs.org/en/latest/index.html Tuesday, September 4, 12
36. Introducing ispyd. • Download site. • https://github.com/GrahamDumpleton/wsgi-shell • Aims of the package. • Provide a generic framework for implementing an interactive console. • The commands you can run are targeted at a specific purpose. • Plugin based so can control what is available and also extendable. • Remotely accessible and execution of commands scriptable. Tuesday, September 4, 12
37. Connecting to processes. $ ispy ispyd.ini (ispyd) servers 1: (1, '/tmp/ispyd-14905.sock') 2: (1, '/tmp/ispyd-14906.sock') 3: (1, '/tmp/ispyd-14907.sock') (ispyd) connect 1 (ispyd:ll345) plugins ['debugger', 'process', 'python', 'wsgi'] Tuesday, September 4, 12
38. DEMO Tuesday, September 4, 12
39. Executing commands. (ispyd:ll345) shell process (process:ll345) help Documented commands (type help <topic>): ======================================== cwd egid euid exit gid help pid prompt uid (process:ll345) cwd /Users/graham Tuesday, September 4, 12
40. Power users. (ispyd:ll345) shell python (python:ll345) console Python 2.6.1 (r261:67515, Jun 24 2010, 21:47:49) [GCC 4.2.1 (Apple Inc. build 5646)] on darwin Type "help", "copyright", "credits" or "license" for more information. (EmbeddedConsole) >>> import os >>> os.getcwd() '/Users/graham' >>> exit() Tuesday, September 4, 12
41. Post-mortem debugging. (ispyd:ll345) shell debugger (debugger:11345) insert __main__:function (debugger:11345) tracebacks {'__main__:function': <traceback object at 0x1013a11b8>} (debugger:11345) debug __main__:function > /Users/graham/wsgi.py(15)function() -> raise RuntimeError('xxx') (Pdb) dir() [] (Pdb) __file__ 'wsgi.py' Tuesday, September 4, 12
42. Active requests. (ispyd:ll345) shell requests (debugger:11345) requests ==== 707 ==== thread_id = 140735076232384 start_time = Mon Apr 9 21:49:54 2012 duration = 0.013629 seconds CONTENT_LENGTH = '' ... File: "wsgi.py", line 25, in <module> application.run(host='0.0.0.0', port=port) ... Tuesday, September 4, 12
43. Extending what is monitored. (ispyd:ll345) shell newrelic (newrelic:ll345) function_trace awesome_dbm:open (newrelic:ll345) function_trace amesome_dbm:_Database._commit Tuesday, September 4, 12
44. Creating plugins. import psutil class Shell(object): name = 'psutil' def do_num_cpus(self, line): print >> self.stdout, psutil.NUM_CPUS def do_cpu_times(self, line): print >> self.stdout, psutil.cpu_times() def do_virtual_memory(self, line): print >> self.stdout, psutil.virtual_memory() def do_swap_memory(self, line): print >> self.stdout, psutil.swap_memory() Tuesday, September 4, 12
45. Ideas for third party plugins. • Memory. • Process memory usage. • Statistics on objects in use (heapy). • State of the garbage collector. • Profiling. • Initiate sampled profiling for selected functions. • Django. • Current configuration. • Details of loaded applications. • Details of registered middleware. • Details of template libraries. • Testing URLs against URL resolver. • Statistics on cache usage. Tuesday, September 4, 12
46. What am I trying to say? • Use monitoring so you know when problems arise. • One tool alone is not going to provide everything. • Use complimentary tools to get a full picture. • Build in mechanisms that allow deeper debugging. • Treat debugging like any other defined process. Tuesday, September 4, 12
47. New Relic 30 Day Free Pro Trail http://newrelic.com/30 Graham.Dumpleton@gmail.com @GrahamDumpleton amjith@newrelic.com @amjithr Tuesday, September 4, 12