2017 - Python Debugging with PUDB

Description

When tracking down a tricky bug, tools are everything. I'll demonstrate three useful debugging tools and we'll see how we can use them to find bugs, whether they are in networking, logic, or performance.

Abstract

Stop using print statements forever! You'll learn how to use these tools: PUDB - an interactive, ncurses debugger Charles - a web debugging proxy cProfile - python's built-in profiling library RunSnakeRun and SnakeViz - Tool for visualizing profile output I'll also talk about the process of debugging and profiling, common error patterns and how to use your time most efficiently.

Bio

Chris Beacham (aka Lady Red) is a python developer and Senior Software Engineer at Hipmunk. She also does performance, sewing, sculpture and painting in her free time, and is a frequent sight at the Noisebridge Hackerspace, where this talk was first delivered.

https://www.youtube.com/watch?v=mbdYATn7h6Q

Transcript

1. Python Debugging with PuDB, Charles, and cProfile Christopher Beacham / Lady Red, Senior Engineer @ Hipmunk Hipmunk: christopher@hipmunk.com Personal: mcscope@gmail.com
2. I write code, and this is a little bit embarrassing, but…
3. I write code, and this is a little bit embarrassing, but… My Code Has Bugs
5. The faster we can find bugs, the faster we can fix them
6. The faster we can find bugs, the faster we can fix them It’s hard to see what a program is doing!
7. Debugging tools can make the invisible visible.
8. PuDB - Interactive visual debugger. Charles Proxy - Web debugging proxy cProfile + others - python profilers and visualization tools Tools we’ll cover:
9. Stop using Print Statements One is never enough You’ll never find a problem you aren’t specifically looking for You have to remember to delete them
10. Debugging Process Systematically check your assumptions in a binary search First Test
11. Debugging Process Systematically check your assumptions in a binary search First Test Second Test
12. Debugging Process Systematically check your assumptions in a binary search First Test Second Test Third Test
13. Debugging Process Systematically check your assumptions in a binary search First Test Second Test Third Test FOUND THE BUG
14. How many of you have used a debugger before?
15. PuDB PuDB is my favorite debugger. It’s very similar to pdb and ipdb, but it’s VISUAL. It show you everything in scope, your code, and a terminal.
26. Let’s USE it!
27. We’re going to use PuDB to debug a fortune webserver written in python (flask)
28. PuDB: Extra Credit - You can use PuDB for unit tests - both in the test, - the code under test, - and you can step smoothly between them - If you use nose testing, you can drop into Pudb on failures with the nose-pudb package - PuDB will catch exceptions, giving you a chance to inspect the entire scope.
30. How many of you have used one of these tools? (Dev tools) nettop curl
31. What is Charles? • Charles is a web debugging proxy • It shows the content and statistics about any HTTP/HTTPS traffic that passes through it. • You can repeat requests, modify, intercept, all the forms of beautiful meddling.
33. Breaking SSL Charles is the Man in the Middle
34. Fortune - now with distributed architecture?
43. (make slide showing editing a request)
53. Let’s USE it!
54. Charles - Extra Credit • It can publish a gist to github of a request/response • You can view xml/json/protocol buffers in a structured way • You can get the curl command for a given request • Use breakpoints or rewrite tool to modify any request in realtime
55. Charles extra credit - continued • You can throttle to mimic low-speed connections • You can blacklist hosts to block connections to them • It can serve local files from a local folder in response to requests to a server • You can use Charles “Mirror” tool to record a mirror of a site to disk, and then use Map Local to serve it back up • … there’s a ton more
56. Charles is nagware After you install it, it’ll keep bugging you until you buy a license. I think it’s just one developer building it, so yeah, if you find it useful, it’s a good cause to buy a license and support his work. (I’m not being compensated for this talk - I just like this software)
58. How many of you have had code that was slow?
59. How many of you have had code that was slow? How many have used profiling to identify why?
60. Is anyone not sure what a profiler is or how it works?
61. Profiling Profiling is a different hippopotamus from debugging.
62. Profiling - Interpreting a profiler output is almost an art.
63. Profiling - Interpreting a profiler output is almost an art. - You can’t recognize wrong unless you would know what right looks like.
64. Profiling - Interpreting a profiler output is almost an art. - You can’t recognize wrong unless you would know what right looks like. - A lot of profiling is reading between the lines
65. Profiling - Always profile before making performance-related improvements.
66. Profiling - Always profile before making performance-related improvements. - Profiling before making performance-related improvements can keep you from wasting your time
67. Profiling - Always profile before making performance-related improvements. - Profiling before making performance-related improvements can keep you from wasting your time - Your assumptions about what is taking the most time are often wrong.
68. Profiling - Always profile before making performance-related improvements. - Profiling before making performance-related improvements can keep you from wasting your time - Your assumptions about what is taking the most time are often wrong. - Speeding up code that is already fast is useless!
69. Profiling - Always profile before making performance-related improvements. - Profiling before making performance-related improvements can keep you from wasting your time - Your assumptions about what is taking the most time are often wrong. - Speeding up code that is already fast is useless! - You must profile with realistic load / realistic data
70. The Sad State of Python Profilers I wanted to tell you that there was an awesome profiler tool you should use...
71. The Sad State of Python Profilers I wanted to tell you that there was an awesome profiler tool you should use...
72. cProfile! Python has 3 built-in profilers, but cProfile is the most commonly used one. It’s in the standard library. python -m cProfile [-o output_file] [-s sort_order] myscript.py Two output formats - binary and human readable.
73. “Human readable” output I find it’s best to sort by cumtime (cumulative time) Difficult to distinguish which times are additive, and which times are nested. Gets confusing for anything more than the simplest program 47371645 function calls in 20.013 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 1 0.001 0.001 20.013 20.013 simulation.py:3(<module>) 2 9.524 4.762 20.006 10.003 simulation.py:24(run_simulation) 2441124 1.842 0.000 2.324 0.000 queue.py:82(enqueue) 2297290 1.804 0.000 2.320 0.000 queue.py:39(enqueue) 2294714 1.369 0.000 1.369 0.000 queue.py:52(dequeue) 18940222 1.260 0.000 1.260 0.000 {method 'random' of '_random.Random' objects} 2438880 1.160 0.000 1.160 0.000 queue.py:95(dequeue) 4738410 0.750 0.000 0.750 0.000 {max} 2297290 0.517 0.000 0.517 0.000 queue.py:28(__init__) 2441124 0.482 0.000 0.482 0.000 queue.py:69(__init__) 2439596 0.347 0.000 0.347 0.000 queue.py:105(is_empty) 2295021 0.342 0.000 0.342 0.000 queue.py:62(is_empty) 2441122 0.300 0.000 0.300 0.000 queue.py:102(size) 2297288 0.282 0.000 0.282 0.000 queue.py:59(size) 9471 0.028 0.000 0.028 0.000 {built-in method now} 1 0.001 0.001 0.004 0.004 random.py:40(<module>) 1 0.002 0.002 0.002 0.002 hashlib.py:56(<module>) 1 0.001 0.001 0.002 0.002 queue.py:1(<module>)
74. 47371645 function calls in 20.013 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 1 0.001 0.001 20.013 20.013 simulation.py:3(<module>) 2 9.524 4.762 20.006 10.003 simulation.py:24(run_simulation) 2441124 1.842 0.000 2.324 0.000 queue.py:82(enqueue) 2297290 1.804 0.000 2.320 0.000 queue.py:39(enqueue) 2294714 1.369 0.000 1.369 0.000 queue.py:52(dequeue) 18940222 1.260 0.000 1.260 0.000 {method 'random' of '_random.Random' objects} 2438880 1.160 0.000 1.160 0.000 queue.py:95(dequeue) 4738410 0.750 0.000 0.750 0.000 {max}
75. cProfile Visualizers cProfile can make binary output that can be read by several tools.
76. pyprof2calltree + qcachegrind
78. while True: now = datetime.now() ...
80. After - datetime.now is no more! while True: now = datetime.now() ... while True: if count % 1000 == 0: now = datetime.now() …
81. Simulation complete, ran 287,768.6 operations per second Simulation complete, ran 419,200.0 operations per second
84. PuDB Install: pip install pudb Invoke import pudb; pudb.set_trace() PUDB https://documen.tician.de/pudb/ Nose-PUDB (for nose testing) - https://pypi.python.org/pypi/nose-pudb
85. Charles https://www.charlesproxy.com
86. Profiling cProfile https://docs.python.org/3/library/profile.html Using cProfile w/ pyprof2calltree and kcachegrind/qcachegrind: https://julien.danjou.info/blog/2015/guide-to-python-profiling-cprofile-concrete-case -carbonara
87. Happy Hunting!!