Профилирование и отладка Django

Владимир Рудных

При написании программы, разработчик примерно представляет себе, как должна работать его программа. Но не всегда его ожидания соответствуют действительности — приложения тормозят, потребляют много ресурсов и вообще ведут себя не так, как задумывалось, особенно под большой нагрузкой. В своём докладе я покажу, как заглянуть "под капот" ваших приложений на Python (и Django в частности): какие способы профилирования бывают и когда их можно использовать, расскажу об отладке приложений и различных инструментах, которые помогают разработчику при разработке.

Transcript

1. Профилирование и отладка
   Django
   Владимир Рудных
   

   View Slide

2. Moscow Django MeetUp №13
   Обо мне
   • технический руководитель
   Календаря Mail.Ru
   • pythonista
   • бывший перловик
   • ленивый программист
   

   View Slide

3. Moscow Django MeetUp №13
   Cбор характеристик работы программы
   с целью их дальнейшей оптимизации.
   Профилирование
   

   View Slide

4. Moscow Django MeetUp №13
   Что собираем?
   • время выполнения строк кода
   • количество вызовов функций
   • время выполнения функций
   • дерево вызовов функций
   • “hot spots”
   • загрузку CPU, использование памяти
   • и т.д.
   

   View Slide

5. Moscow Django MeetUp №13
   Project Euler
   http://projecteuler.net
   Тренируемся
   

   View Slide

6. Moscow Django MeetUp №13
   Простые делители числа 13195 — это 5, 7, 13 и 29.
   Какой самый большой делитель числа 600851475143,
   являющийся простым числом?
   Project Euler: задача 3
   

   View Slide

7. Moscow Django MeetUp №13
   1 """Project Euler problem 3 solve"""
   2
   3
   4 def is_prime(num):
   5 """Checks if num is prime number"""
   6 for i in range(2, num):
   7 if not num % i:
   8 return False
   9 return True
   10
   11
   12 def prime_factors(num):
   13 """Find prime factors of num"""
   14 result = []
   15 for i in range(2, num):
   16 if is_prime(i) and not num % i:
   17 result.append(i)
   18 return result
   19
   20
   21 if __name__ == '__main__':
   22 print "Answer: %d" % prime_factors(600851475143)[-1]
   Project Euler: задача 3
   

   View Slide

8. Moscow Django MeetUp №13
   

   View Slide

9. Moscow Django MeetUp №13
   

   View Slide

10. Moscow Django MeetUp №13
    Профилирование начинается в голове.
    Инструменты — всего лишь инструменты.
    Искусство профилирования
    

    View Slide

11. Moscow Django MeetUp №13
    1 """Project Euler problem 3 solve"""
    2 from math import sqrt
    3
    4
    5 def is_prime(num):
    6 """Checks if num is prime number"""
    7 for i in range(2, int(sqrt(num)) + 1):
    8 if not num % i:
    9 return False
    10 return True
    11
    12
    13 def prime_factors(num):
    14 """Find prime factors of num"""
    15 result = []
    16 for i in range(2, int(sqrt(num)) + 1):
    17 if is_prime(i) and not num % i:
    18 result.append(i)
    19 return result
    20
    21
    22 if __name__ == '__main__':
    23 print "Answer: %d" % prime_factors(600851475143)[-1]
    Project Euler: задача 3
    

    View Slide

12. Moscow Django MeetUp №13
    Подходы к профилированию
    • ручное профилирование
    • с помощью инструментов
    

    View Slide

13. Moscow Django MeetUp №13
    Ручное профилирование
    

    View Slide

14. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ time python max_prime_factor.py
    Answer: 6857
    python max_prime_factor.py 20,00s user 0,19s system 82% cpu 24,445 total
    Ручное профилирование
    

    View Slide

15. Moscow Django MeetUp №13
    1 """Project Euler problem 3 solve"""
    2 import time
    3 from math import sqrt
    4
    5
    6 def is_prime(num):
    7 """Checks if num is prime number"""
    8 for i in range(2, int(sqrt(num)) + 1):
    9 if not num % i:
    10 return False
    11 return True
    12
    13
    14 def prime_factors(num):
    15 """Find prime factors of num"""
    16 result = []
    17 for i in range(2, int(sqrt(num)) + 1):
    18 if is_prime(i) and not num % i:
    19 result.append(i)
    20 return result
    21
    22
    23 if __name__ == '__main__':
    24 start = time.time()
    25 print "Answer: %d" % prime_factors(600851475143)[-1]
    26 print "Time: %f s" % (time.time() - start)
    Ручное профилирование
    

    View Slide

16. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python max_prime_factor.py
    Answer: 6857
    Time: 23.531779 s
    Ручное профилирование
    

    View Slide

17. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python max_prime_factor.py
    Answer: 6857
    Time: 21.143574 s
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python max_prime_factor.py
    Answer: 6857
    Time: 22.638407 s
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python max_prime_factor.py
    Answer: 6857
    Time: 20.774542 s
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python max_prime_factor.py
    Answer: 6857
    Time: 22.272329 s
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python max_prime_factor.py
    Answer: 6857
    Time: 23.562760 s
    Ручное профилирование
    

    View Slide

18. Moscow Django MeetUp №13
    timeit
    http://docs.python.org/2/library/timeit.html
    Ручное профилирование
    

    View Slide

19. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m timeit -n 10 -s'from max_prime_factor import prime_factors' 'prime_factors(600851475143)'
    10 loops, best of 3: 22.3 sec per loop
    timeit
    

    View Slide

20. Moscow Django MeetUp №13
    Ручное профилирование
    очень простое применение
    ограниченно подходит
    для продакшена
    вставка чужеродного кода в проект
    никакой информации о коде
    (кроме времени выполнения)
    анализ результатов может быть
    затруднительным
    

    View Slide

21. Moscow Django MeetUp №13
    — Зацени, мой код быстрее твоего!
    Применение
    

    View Slide

22. Moscow Django MeetUp №13
    Применение
    

    View Slide

23. Moscow Django MeetUp №13
    Сбор статистики времени выполнения кода.
    Например, в graphite или statsd:
    Применение в реальной жизни
    

    View Slide

24. Moscow Django MeetUp №13
    1 """Collect profiling statistic into graphite"""
    2 import socket
    3 import time
    4
    5
    6 CARBON_SERVER = '127.0.0.1'
    7 CARBON_PORT = 2003
    8
    9
    10 class Stats(object):
    11 """Context manager for send stats to graphite"""
    12
    13 def __init__(self, name):
    14 self.name = name
    15
    16 def __enter__(self):
    17 self.start = time.time()
    18 return self
    19
    20 def __exit__(self, *args):
    21 duration = (time.time() - self.start) * 1000 # msec
    22 message = '%s %d %d\n' % (self.name, duration, time.time())
    23
    24 sock = socket.socket()
    25 sock.connect((CARBON_SERVER, CARBON_PORT))
    26 sock.sendall(message)
    27 sock.close()
    Менеджер контекста
    

    View Slide

25. Moscow Django MeetUp №13
    from django.core.mail import send_mail
    from profiling.context_managers import Stats
    ...
    with Stats('django_project.profiling.send_email'):
    send_mail(
    'Subject here',
    'Here is the message.',
    'from@example.com',
    ['to@example.com'],
    fail_silently=False
    )
    Пример использования
    

    View Slide

26. Moscow Django MeetUp №13
    1 """Collect profiling statistic into graphite"""
    2 import socket
    3 import time
    4
    5
    6 CARBON_SERVER = '127.0.0.1'
    7 CARBON_PORT = 2003
    8
    9
    10 def stats(name):
    11 """Decorator for send stats to graphite"""
    12 def _timing(func):
    13 def _wrapper(*args, **kwargs):
    14 start = time.time()
    15 result = func(*args, **kwargs)
    16 duration = (time.time() - start) * 1000 # msec
    17 message = '%s %d %d\n' % (name, duration, time.time())
    18
    19 sock = socket.socket()
    20 sock.connect((CARBON_SERVER, CARBON_PORT))
    21 sock.sendall(message)
    22 sock.close()
    23
    24 return result
    25 return _wrapper
    26 return _timing
    Декоратор
    

    View Slide

27. Moscow Django MeetUp №13
    from django.db import models
    from profiling.decorator import stats
    ...
    class Model(model.Model):
    ...
    @stats('django_project.profiling.application.save')
    def save(self, *args, **kwargs):
    # do some hard work like thumbnail generation
    super(Model, self).save(*args, **kwargs)
    Пример использования
    

    View Slide

28. Moscow Django MeetUp №13
    Статистика профилирования
    

    View Slide

29. Moscow Django MeetUp №13
    Профилирование
    с помощью инструментов
    

    View Slide

30. Moscow Django MeetUp №13
    Инструменты для профилирования
    •Deterministic (event-based)
    •Statistical
    

    View Slide

31. Moscow Django MeetUp №13
    def is_prime(num):
    """Checks if num is prime number"""
    for i in range(2, num):
    if not num % i:
    return False
    return True
    Deterministic profilers
    @profile
    def is_prime(num):
    """Checks if num is prime number"""
    for i in range(2, num):
    if not num % i:
    return False
    return True
    

    View Slide

32. Moscow Django MeetUp №13
    def is_prime(num):
    """Checks if num is prime number"""
    with profile():
    for i in range(2, num):
    if not num % i:
    return False
    return True
    Deterministic profilers
    def is_prime(num):
    """Checks if num is prime number"""
    profile.start()
    for i in range(2, num):
    if not num % i:
    return False
    profile.stop()
    return True
    

    View Slide

33. Moscow Django MeetUp №13
    Deterministic profilers
    def foo()
    def bar()
    def baz() def ololo()
    

    View Slide

34. Moscow Django MeetUp №13
    Deterministic profilers
    вся информация о коде
    множество инструментов для анализа
    очень медленно
    непригодно для продакшена
    (или крайне ограниченно)
    

    View Slide

35. Moscow Django MeetUp №13
    Statistical profilers
    def foo() def bar() def baz()
    def foo() def bar() def baz()
    Timer: 1ms
    Timer: 10ms
    

    View Slide

36. Moscow Django MeetUp №13
    Statistical profilers
    def foo() def foo() def foo() def foo()
    def foo()
    def foo()
    

    View Slide

37. Moscow Django MeetUp №13
    Statistical profilers
    можно пускать в продакшн
    (практически не влияет на быстродействие)
    не вся информация о коде
    мало инструментов для анализа
    

    View Slide

38. Moscow Django MeetUp №13
    Deterministic profilers
    • profile
    • cProfile
    • hotshot
    • kcachegrind
    • RunSnakeRun
    • gprof2dot
    • pycallgraph
    • line_profiler
    • memory_profiler
    • dowser
    • guppy
    • muppy
    • memprof
    • objgraph
    “тысячи их”...
    

    View Slide

39. Moscow Django MeetUp №13
    cProfile
    http://docs.python.org/2/library/profile.html
    Инструменты для профилирования
    

    View Slide

40. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m cProfile -s time max_prime_factor.py
    Answer: 6857
    2325444 function calls in 21.912 seconds
    Ordered by: internal time
    ncalls tottime percall cumtime percall filename:lineno(function)
    775145 14.240 0.000 21.233 0.000 max_prime_factor.py:5(is_prime)
    775146 6.779 0.000 6.779 0.000 {range}
    1 0.630 0.630 21.909 21.909 max_prime_factor.py:13(prime_factors)
    775146 0.260 0.000 0.260 0.000 {math.sqrt}
    1 0.003 0.003 21.912 21.912 max_prime_factor.py:1()
    4 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
    1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
    cProfile
    

    View Slide

41. Moscow Django MeetUp №13
    1 """Project Euler problem 3 solve"""
    2 from math import sqrt
    3
    4
    5 def is_prime(num):
    6 """Checks if num is prime number"""
    7 for i in range(2, int(sqrt(num)) + 1):
    8 if not num % i:
    9 return False
    10 return True
    11
    12
    13 def prime_factors(num):
    14 """Find prime factors of num"""
    15 result = []
    16 for i in range(2, int(sqrt(num)) + 1):
    17 if is_prime(i) and not num % i:
    18 result.append(i)
    19 return result
    20
    21
    22 if __name__ == '__main__':
    23 print "Answer: %d" % prime_factors(600851475143)[-1]
    Project Euler: задача 3
    

    View Slide

42. Moscow Django MeetUp №13
    1 """Project Euler problem 3 solve"""
    2 from math import sqrt
    3
    4
    5 def is_prime(num):
    6 """Checks if num is prime number"""
    7 for i in range(2, int(sqrt(num)) + 1):
    8 if not num % i:
    9 return False
    10 return True
    11
    12
    13 def prime_factors(num):
    14 """Find prime factors of num"""
    15 result = []
    16 for i in range(2, int(sqrt(num)) + 1):
    17 if not num % i and is_prime(i):
    18 result.append(i)
    19 return result
    20
    21
    22 if __name__ == '__main__':
    23 print "Answer: %d" % prime_factors(600851475143)[-1]
    Project Euler: задача 3
    

    View Slide

43. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m cProfile -s time max_prime_factor.py
    Answer: 6857
    30 function calls in 0.225 seconds
    Ordered by: internal time
    ncalls tottime percall cumtime percall filename:lineno(function)
    1 0.179 0.179 0.250 0.250 max_prime_factor.py:13(prime_factors)
    8 0.070 0.009 0.070 0.009 {range}
    1 0.003 0.003 0.253 0.253 max_prime_factor.py:1()
    7 0.000 0.000 0.000 0.000 max_prime_factor.py:5(is_prime)
    8 0.000 0.000 0.000 0.000 {math.sqrt}
    4 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
    1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
    cProfile
    

    View Slide

44. Moscow Django MeetUp №13
    Ускорил код в сто раз
    

    View Slide

45. Moscow Django MeetUp №13
    import cProfile
    def profile(func):
    """Decorator for run function profile"""
    def wrapper(*args, **kwargs):
    profile_filename = func.__name__ + '.profile'
    profiler = cProfile.Profile()
    result = profiler.runcall(func, *args, **kwargs)
    profiler.dump_stats(profile_filename)
    return result
    return wrapper
    @profile
    def foo():
    ...
    cProfile: декоратор
    

    View Slide

46. Moscow Django MeetUp №13
    hotshot
    http://docs.python.org/2/library/hotshot.html
    Инструменты для профилирования
    

    View Slide

47. Moscow Django MeetUp №13
    import hotshot
    prof = hotshot.Profile("profile_name.prof")
    prof.start()
    # your code goes here
    prof.stop()
    prof.close()
    hotshot: использование
    

    View Slide

48. Moscow Django MeetUp №13
    import hotshot
    def profile(func):
    """Decorator for run function profile"""
    def wrapper(*args, **kwargs):
    profile_filename = func.__name__ + '.profile'
    profiler = hotshot.Profile(profile_filename)
    profiler.start()
    result = func(*args, **kwargs)
    profiler.stop()
    profiler.close()
    return result
    return wrapper
    @profile
    def foo():
    ...
    hotshot: декоратор
    

    View Slide

49. Moscow Django MeetUp №13
    cProfile, hotshot
    мощные инструменты
    достаточно простые
    дерево вызовов функций
    сильно влияют на производительность
    анализ результатов может быть
    затруднительным
    

    View Slide

50. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ time python max_prime_factor.py
    Answer: 6857
    python max_prime_factor.py 0,18s user 0,01s system 95% cpu 0,199 total
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ time python -m cProfile max_prime_factor.py
    Answer: 6857
    22 function calls in 0.252 seconds
    Ordered by: standard name
    ncalls tottime percall cumtime percall filename:lineno(function)
    1 0.005 0.005 0.252 0.252 max_prime_factor.py:1()
    1 0.247 0.247 0.247 0.247 max_prime_factor.py:13(prime_factors)
    7 0.000 0.000 0.000 0.000 max_prime_factor.py:5(is_prime)
    8 0.000 0.000 0.000 0.000 {math.sqrt}
    4 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
    1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
    python -m cProfile max_prime_factor.py 0,23s user 0,09s system 58% cpu 0,541 total
    cProfile: производительность
    

    View Slide

51. Moscow Django MeetUp №13
    Сохраняем результаты профилирования
    в файл для дальнейшего анализа:
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m cProfile -o max_prime_factor.prof max_prime_factor.py
    Answer: 6857
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ ls
    max_prime_factor.prof max_prime_factor.py
    cProfile: анализ результатов
    

    View Slide

52. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ ipython
    In [1]: import pstats
    In [2]: p = pstats.Stats('max_prime_factor.prof')
    In [3]: p.sort_stats('calls')
    Out[3]:
    In [4]: p.print_stats(5)
    22 function calls in 0.166 seconds
    Ordered by: call count
    List reduced from 6 to 5 due to restriction <5>
    ncalls tottime percall cumtime percall filename:lineno(function)
    8 0.000 0.000 0.000 0.000 {math.sqrt}
    7 0.000 0.000 0.000 0.000 max_prime_factor.py:5(is_prime)
    4 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
    1 0.003 0.003 0.166 0.166 max_prime_factor.py:1()
    1 0.163 0.163 0.163 0.163 max_prime_factor.py:13(prime_factors)
    Out[4]:
    Анализ: pstats
    

    View Slide

53. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pip install pyprof2calltree
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pyprof2calltree -i max_prime_factor.prof -o max_prime_factor.kgrind
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pyprof2calltree -i max_prime_factor.prof -k
    Анализ: kcachegrind
    

    View Slide

54. Moscow Django MeetUp №13
    Анализ: kcachegrind
    

    View Slide

55. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ brew install wxwidgets
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pip install SquareMap RunSnakeRun
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ runsnake max_prime_factor.prof
    Анализ: RunSnakeRun
    

    View Slide

56. Moscow Django MeetUp №13
    Анализ: RunSnakeRun
    

    View Slide

57. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ brew install graphviz
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pip install gprof2dot
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ gprof2dot -f pstats max_prime_factor.prof | dot -Tpng -o max_prime_factor.png
    Анализ: gprof2dot
    

    View Slide

58. Moscow Django MeetUp №13
    Анализ: gprof2dot
    

    View Slide

59. Moscow Django MeetUp №13
    Но где же Django?
    

    View Slide

60. Moscow Django MeetUp №13
    Профилируем Django
    • Устанавливаем модуль:
    ➜ pip install django-extensions
    • Добавляем application в Django:
    INSTALLED_APPS += ('django_extensions',)
    • Запускаем тестовый сервер:
    ➜ python manage.py runprofileserver \
    --use-cprofile \
    --prof-path=/tmp/prof/
    

    View Slide

61. Moscow Django MeetUp №13
    Получаем по одному *.prof файлу на запрос:
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ ls /tmp/prof/
    admin.000276ms.1374075009.prof
    admin.account.user.000278ms.1374075014.prof
    admin.jsi18n.000185ms.1374075018.prof
    favicon.ico.000017ms.1374075001.prof
    root.000073ms.1374075004.prof
    static.admin.css.base.css.000011ms.1374075010.prof
    static.admin.css.forms.css.000013ms.1374075017.prof
    static.admin.img.icon-yes.gif.000001ms.1374075015.prof
    static.admin.img.sorting-icons.gif.000001ms.1374075015.prof
    static.admin.js.core.js.000018ms.1374075014.prof
    static.admin.js.jquery.js.000003ms.1374075014.prof
    static.css.bootstrap-2.3.2.min.css.000061ms.1374074996.prof
    static.img.glyphicons-halflings.png.000001ms.1374075005.prof
    static.js.bootstrap-2.3.2.min.js.000004ms.1374074996.prof
    static.js.jquery-2.0.2.min.js.000001ms.1374074996.prof
    user.login.000187ms.1374075001.prof
    А дальшё всё как обычно:
    Профилируем Django
    

    View Slide

62. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ ipython
    In [1]: import pstats
    In [2]: p = pstats.Stats('/tmp/prof/user.login.000187ms.1374075001.prof')
    In [3]: p.sort_stats('calls')
    Out[3]:
    In [4]: p.print_stats(5)
    36854 function calls (35710 primitive calls) in 0.187 seconds
    Ordered by: call count
    List reduced from 774 to 5 due to restriction <5>
    ncalls tottime percall cumtime percall filename:lineno(function)
    4714 0.002 0.000 0.002 0.000 {method 'append' of 'list' objects}
    3562 0.003 0.000 0.003 0.000 {isinstance}
    2456 0.003 0.000 0.003 0.000 {method 'startswith' of 'unicode' objects}
    1058/1048 0.002 0.000 0.002 0.000 {getattr}
    979/962 0.000 0.000 0.025 0.000 {len}
    Out[4]:
    Анализ: pstats
    

    View Slide

63. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pyprof2calltree -i /tmp/prof/user.login.000187ms.1374075001.prof -k
    Анализ: kcachegrind
    

    View Slide

64. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ runsnake /tmp/prof/user.login.000187ms.1374075001.prof
    Анализ: RunSnakeRun
    

    View Slide

65. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ gprof2dot -f pstats /tmp/prof/user.login.000187ms.1374075001.prof | dot -Tpng -o login.png
    Анализ: gprof2dot
    

    View Slide

66. Moscow Django MeetUp №13
    Ещё инструменты
    

    View Slide

67. Moscow Django MeetUp №13
    pycallgraph
    http://pycallgraph.slowchop.com/
    Инструменты для профилирования
    

    View Slide

68. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pip install pycallgraph
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pycallgraph max_prime_factor.py
    Python Call Graph v0.5.1
    Starting trace
    Answer: 6857
    Creating pycallgraph.png
    Done!
    pycallgraph
    

    View Slide

69. Moscow Django MeetUp №13
    import pycallgraph
    pycallgraph.start_trace()
    # your code goes here
    pycallgraph.make_dot_graph('call-graph.png')
    pycallgraph
    

    View Slide

70. Moscow Django MeetUp №13
    line_profiler
    https://bitbucket.org/robertkern/line_profiler
    Инструменты для профилирования
    

    View Slide

71. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ kernprof.py -v -l max_prime_factor.py
    Function: is_prime at line 5
    Total time: 0.001412 s
    Line # Hits Time Per Hit % Time Line Contents
    ==============================================================
    6 def is_prime(num):
    7 """Checks if num is prime number"""
    8 366 767 2.1 54.3 for i in range(2, int(sqrt(num)) + 1):
    9 362 614 1.7 43.5 if not num % i:
    10 3 23 7.7 1.6 return False
    11 4 8 2.0 0.6 return True
    Function: prime_factors at line 14
    Total time: 2.67703 s
    Line # Hits Time Per Hit % Time Line Contents
    ==============================================================
    15 def prime_factors(num):
    16 """Find prime factors of num"""
    17 1 4 4.0 0.0 result = []
    18 775146 1320370 1.7 49.3 for i in range(2, int(sqrt(num)) + 1):
    19 775145 1356632 1.8 50.7 if not num % i and is_prime(i):
    20 4 16 4.0 0.0 result.append(i)
    21 1 10 10.0 0.0 return result
    line_profiler
    

    View Slide

72. Moscow Django MeetUp №13
    memory_profiler
    https://github.com/fabianp/memory_profiler
    Инструменты для профилирования
    

    View Slide

73. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m memory_profiler max_prime_factor.py
    Line # Mem usage Increment Line Contents
    ================================================
    6 def is_prime(num):
    7 32.469 MB 0.000 MB """Checks if num is prime number"""
    8 57.414 MB 24.945 MB for i in range(2, int(sqrt(num)) + 1):
    9 57.414 MB 0.000 MB if not num % i:
    10 32.566 MB -24.848 MB return False
    11 33.047 MB 0.480 MB return True
    Line # Mem usage Increment Line Contents
    ================================================
    15 def prime_factors(num):
    16 8.379 MB 0.000 MB """Find prime factors of num"""
    17 8.379 MB 0.000 MB result = []
    18 75.332 MB 66.953 MB for i in range(2, int(sqrt(num)) + 1):
    19 33.047 MB -42.285 MB if not num % i and is_prime(i):
    20 75.332 MB 42.285 MB result.append(i)
    21 75.332 MB 0.000 MB return result
    memory_profiler
    

    View Slide

74. Moscow Django MeetUp №13
    1 """Project Euler problem 3 solve"""
    2 from math import sqrt
    3
    4
    5 def is_prime(num):
    6 """Checks if num is prime number"""
    7 for i in xrange(2, int(sqrt(num)) + 1):
    8 if not num % i:
    9 return False
    10 return True
    11
    12
    13 def prime_factors(num):
    14 """Find prime factors of num"""
    15 result = []
    16 for i in xrange(2, int(sqrt(num)) + 1):
    17 if not num % i and is_prime(i):
    18 result.append(i)
    19 return result
    20
    21
    22 if __name__ == '__main__':
    23 print "Answer: %d" % prime_factors(600851475143)[-1]
    Project Euler: задача 3
    

    View Slide

75. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m memory_profiler max_prime_factor.py
    Line # Mem usage Increment Line Contents
    ================================================
    6 def is_prime(num):
    7 8.391 MB 0.000 MB """Checks if num is prime number"""
    8 22.605 MB 14.215 MB for i in xrange(2, int(sqrt(num)) + 1):
    9 22.605 MB 0.000 MB if not num % i:
    10 8.484 MB -14.121 MB return False
    11 8.965 MB 0.480 MB return True
    Line # Mem usage Increment Line Contents
    ================================================
    15 def prime_factors(num):
    16 8.379 MB 0.000 MB """Find prime factors of num"""
    17 8.379 MB 0.000 MB result = []
    18 34.141 MB 25.762 MB for i in xrange(2, int(sqrt(num)) + 1):
    19 8.965 MB -25.176 MB if not num % i and is_prime(i):
    20 34.141 MB 25.176 MB result.append(i)
    21 34.141 MB 0.000 MB return result
    memory_profiler
    

    View Slide

76. Moscow Django MeetUp №13
    И ещё инструменты
    

    View Slide

77. Moscow Django MeetUp №13
    Профилирование памяти
    Dowser
    http://www.aminus.net/wiki/Dowser
    Инструменты для профилирования
    

    View Slide

78. Moscow Django MeetUp №13
    Профилирование памяти
    guppy
    http://guppy-pe.sourceforge.net/
    Инструменты для профилирования
    

    View Slide

79. Moscow Django MeetUp №13
    Обнаружение утечек памяти
    muppy
    http://pythonhosted.org/Pympler/muppy.html
    Инструменты для профилирования
    

    View Slide

80. Moscow Django MeetUp №13
    Профилирование памяти
    memprof
    http://jmdana.github.io/memprof/
    Инструменты для профилирования
    

    View Slide

81. Moscow Django MeetUp №13
    Исследование объектов
    objgraph
    http://mg.pov.lt/objgraph/
    Инструменты для профилирования
    

    View Slide

82. Moscow Django MeetUp №13
    Statistical profilers
    • StatProf
    • Plop
    • New Relic
    

    View Slide

83. Moscow Django MeetUp №13
    statprof
    https://github.com/bos/statprof.py
    Инструменты для профилирования
    

    View Slide

84. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pip install statprof
    import statprof
    statprof.start()
    try:
    function()
    finally:
    statprof.stop()
    statprof.display()
    import statprof
    with statprof.profile():
    function()
    statprof
    

    View Slide

85. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ time python max_prime_factor.py
    Answer: 6857
    python max_prime_factor.py 10,42s user 0,04s system 97% cpu 10,750 total
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ time python max_prime_factor.py
    Answer: 6857
    % cumulative self
    time seconds seconds name
    83.03 8.82 8.82 max_prime_factor.py:9:is_prime
    13.52 1.44 1.44 max_prime_factor.py:8:is_prime
    2.01 10.62 0.21 max_prime_factor.py:18:prime_factors
    0.88 0.09 0.09 max_prime_factor.py:6:is_prime
    0.48 0.05 0.05 max_prime_factor.py:10:is_prime
    0.06 0.01 0.01 max_prime_factor.py:11:is_prime
    0.03 10.62 0.00 max_prime_factor.py:26:
    ---
    Sample count: 3535
    Total time: 10.620000 seconds
    python max_prime_factor.py 10,56s user 0,17s system 90% cpu 11,908 total
    statprof
    

    View Slide

86. Moscow Django MeetUp №13
    statprof
    • Устанавливаем zeromq (нужна для работы):
    ➜ brew install zmq
    • Устанавливаем модуль:
    ➜ pip install statprof django-live-profiler
    • Запускаем аггрегатор:
    ➜ aggregated --host 127.0.0.1 --port 5556
    

    View Slide

87. Moscow Django MeetUp №13
    statprof
    • Добавляем application в Django:
    INSTALLED_APPS += ('profiler',)
    • Добавляем middleware:
    MIDDLEWARE_CLASSES += (
    'profiler.middleware.ProfilerMiddleware',
    'profiler.middleware.StatProfMiddleware')
    • Добавляем urls:
    url(r'^profiler/', include('profiler.urls'))
    • Запускаем Django:
    ➜ python manage.py runserver --noreload --nothreading
    

    View Slide

88. Moscow Django MeetUp №13
    statprof
    

    View Slide

89. Moscow Django MeetUp №13
    statprof
    

    View Slide

90. Moscow Django MeetUp №13
    statprof
    небольшой оверхед
    можно пускать в продакшн
    (если осторожно)
    профилирование SQL-запросов
    сложная установка, зависимости
    мало данных на выходе
    

    View Slide

91. Moscow Django MeetUp №13
    plop
    https://github.com/bdarnell/plop
    Инструменты для профилирования
    

    View Slide

92. Moscow Django MeetUp №13
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ pip install plop tornado
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m plop.collector max_prime_factor.py
    Answer: 6857
    profile output saved to /tmp/plop.out
    overhead was 4.78124272996e-05 per sample (0.00478124272996%)
    rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
    ➜ python -m plop.viewer --datadir=/tmp/
    plop
    

    View Slide

93. Moscow Django MeetUp №13
    plop
    

    View Slide

94. Moscow Django MeetUp №13
    plop
    

    View Slide

95. Moscow Django MeetUp №13
    plop
    • Устанавливаем модули:
    ➜ pip install plop django-plop tornado
    • Добавляем application в Django:
    INSTALLED_APPS += ('django_plop',)
    • Добавляем middleware:
    MIDDLEWARE_CLASSES += (
    'django_plop.middleware.PlopMiddleware',)
    • Указываем путь для сохранения результатов:
    PLOP_DIR = os.path.join(ROOT_DIR, 'plop')
    

    View Slide

96. Moscow Django MeetUp №13
    plop
    • Запускаем Django:
    ➜ python manage.py runserver --noreload --nothreading
    • Запускаем просмотр результатов:
    ➜ python -m plop.viewer --datadir=plop
    

    View Slide

97. Moscow Django MeetUp №13
    plop
    минимальный оверхед (около 2%)
    можно пускать в продакшн
    сложная установка, зависимости
    очень мало данных на выходе
    

    View Slide

98. Moscow Django MeetUp №13
    New Relic
    http://newrelic.com/
    Инструменты для профилирования
    

    View Slide

99. Moscow Django MeetUp №13
    New Relic
    

    View Slide

100. Moscow Django MeetUp №13
     New Relic
     

     View Slide

101. Moscow Django MeetUp №13
     New Relic
     

     View Slide

102. Moscow Django MeetUp №13
     New Relic
     предназначен для продакшена
     огромный функционал
     платный (есть бесплатная версия)
     данные отправляются на чужие
     серверы
     

     View Slide

103. Moscow Django MeetUp №13
     Django Debug Toolbar
     https://github.com/django-debug-toolbar/django-debug-toolbar
     Инструменты для профилирования
     

     View Slide

104. Moscow Django MeetUp №13
     Django Debug Toolbar
     • Устанавливаем модули:
     ➜ pip install django-debug-toolbar
     • Добавляем application в Django:
     INSTALLED_APPS += ('debug_toolbar',)
     • Добавляем middleware:
     MIDDLEWARE_CLASSES += (
     'debug_toolbar.middleware.DebugToolbarMiddleware',)
     • Указываем IP для которых показываем тулбар:
     INTERNAL_IPS = ('127.0.0.1',)
     

     View Slide

105. Moscow Django MeetUp №13
     Django Debug Toolbar
     

     View Slide

106. Moscow Django MeetUp №13
     Django Debug Toolbar
     

     View Slide

107. Moscow Django MeetUp №13
     Django Debug Toolbar
     

     View Slide

108. Moscow Django MeetUp №13
     Django Debug Toolbar
     прост в установке и использовании
     огромный функционал
     расширяемый (плагины)
     не для продакшена (?)
     данные никуда не сохраняются
     (только просмотр в реальном времени)
     

     View Slide

109. Moscow Django MeetUp №13
     Django StatsD
     https://github.com/andymckay/django-statsd
     Инструменты для профилирования
     

     View Slide

110. Moscow Django MeetUp №13
     Django StatsD
     • Устанавливаем модули:
     ➜ pip install django-statsd-mozilla
     • Добавляем application в Django:
     INSTALLED_APPS += ('django_statsd',)
     • Добавляем middleware:
     MIDDLEWARE_CLASSES += (
     'django_statsd.middleware.GraphiteRequestTimingMiddleware',
     'django_statsd.middleware.GraphiteMiddleware',)
     • Указываем, что хотим получать тайминги БД:
     STATSD_PATCHES = ['django_statsd.patches.db']
     

     View Slide

111. Moscow Django MeetUp №13
     Django StatsD
     

     View Slide

112. Moscow Django MeetUp №13
     Django StatsD
     прост в установке и использовании
     используется в продакшене
     мало информации (количество/время)
     Нужен graphite и statsd (must-have)
     

     View Slide

113. Moscow Django MeetUp №13
     Обнаружение, локализация
     и устранение ошибок.
     Отладка
     

     View Slide

114. Moscow Django MeetUp №13
     The Python Debugger
     http://docs.python.org/2/library/pdb.html
     Инструменты для отладки
     

     View Slide

115. Moscow Django MeetUp №13
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ python -m pdb max_prime_factor.py
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(1)()
     -> """Project Euler problem 3 solve"""
     (Pdb) next
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(2)()
     -> from math import sqrt
     (Pdb) next
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(5)()
     -> def is_prime(num):
     (Pdb) next
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(13)()
     -> def prime_factors(num):
     (Pdb) next
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(22)()
     -> if __name__ == '__main__':
     (Pdb) next
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(23)()
     -> print "Answer: %d" % prime_factors(600851475143)[-1]
     (Pdb) next
     Answer: 6857
     --Return--
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(23)()->None
     -> print "Answer: %d" % prime_factors(600851475143)[-1]
     (Pdb) quit
     pdb
     

     View Slide

116. Moscow Django MeetUp №13
     1 """Project Euler problem 3 solve"""
     2 from math import sqrt
     3
     4
     5 def is_prime(num):
     6 """Checks if num is prime number"""
     7 import pdb; pdb.set_trace()
     8 for i in xrange(2, int(sqrt(num)) + 1):
     9 if not num % i:
     10 return False
     11 return True
     12
     13
     14 def prime_factors(num):
     15 """Find prime factors of num"""
     16 result = []
     17 for i in xrange(2, int(sqrt(num)) + 1):
     18 if not num % i and is_prime(i):
     19 result.append(i)
     20 return result
     21
     22
     23 if __name__ == '__main__':
     24 print "Answer: %d" % prime_factors(600851475143)[-1]
     pdb
     

     View Slide

117. Moscow Django MeetUp №13
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ python max_prime_factor.py
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(8)is_prime()
     -> for i in xrange(2, int(sqrt(num)) + 1):
     (Pdb) list
     3
     4
     5 def is_prime(num):
     6 """Checks if num is prime number"""
     7 import pdb; pdb.set_trace()
     8 -> for i in xrange(2, int(sqrt(num)) + 1):
     9 if not num % i:
     10 return False
     11 return True
     12
     13
     (Pdb) next
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(9)is_prime()
     -> if not num % i:
     (Pdb) continue
     > /home/rudnyh/work/python-profiling/max_prime_factor.py(8)is_prime()
     -> for i in xrange(2, int(sqrt(num)) + 1):
     (Pdb)
     pdb
     

     View Slide

118. Moscow Django MeetUp №13
     pdb
     практически неограниченный функционал
     не очень удобно
     

     View Slide

119. Moscow Django MeetUp №13
     django-pdb
     https://github.com/tomchristie/django-pdb
     Инструменты для отладки
     

     View Slide

120. Moscow Django MeetUp №13
     django-pdb
     • Устанавливаем модули:
     ➜ pip install django-pdb
     • Добавляем application в Django:
     INSTALLED_APPS += ('django_pdb',)
     • Добавляем middleware:
     MIDDLEWARE_CLASSES += ('django_pdb.middleware.PdbMiddleware',)
     

     View Slide

121. Moscow Django MeetUp №13
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ python manage.py runserver
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ python manage.py runserver --pdb
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ python manage.py runserver --ipdb
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ python manage.py runserver --pm
     django-pdb
     

     View Slide

122. Moscow Django MeetUp №13
     IPython pdb
     https://github.com/gotcha/ipdb
     Инструменты для отладки
     

     View Slide

123. Moscow Django MeetUp №13
     ipdb
     подсветка кода
     автодополнение
     лучше traceback и introspection
     консоль (спорно)
     

     View Slide

124. Moscow Django MeetUp №13
     ipdbplugin
     https://github.com/flavioamieiro/nose-ipdb
     Инструменты для отладки
     

     View Slide

125. Moscow Django MeetUp №13
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ pip install ipdbplugin
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ nosetests --ipdb
     rudnyh@work:~/work/python-profiling (venv: python-profiling) (git: master|✔)
     ➜ nosetests --ipdb-failures
     ipdbplugin
     

     View Slide

126. Moscow Django MeetUp №13
     PyCharm
     http://www.jetbrains.com/pycharm/
     Инструменты для отладки
     

     View Slide

127. Moscow Django MeetUp №13
     PyCharm
     

     View Slide

128. Moscow Django MeetUp №13
     PyCharm
     отладка прямо в редакторе
     установка breakpoint кликом мышки
     GUI (спорно)
     

     View Slide

129. Moscow Django MeetUp №13
     Пожалуй, хватит
     

     View Slide

130. Moscow Django MeetUp №13
     Вопросы?
     

     View Slide

131. Moscow Django MeetUp №13
     Контакты
     •Владимир Рудных
     • rudnyh@corp.mail.ru
     • github.com/dreadatour
     • dreadatour.habrahabr.ru
     

     View Slide