6

В настоящее время я развертываю Django w/Django-Rest-Framework на моем маленьком сервере экземпляров EC2, чтобы предоставить набор API для нескольких приложений для Android.Django Rest Framework/проблема с производительностью Django

Проблема в том, что я столкнулся с серьезной проблемой производительности, которую мне пришлось профилировать. Я узнал, что большую часть времени для одного запроса тратится внутри ядра DRF.

Извините за то, что вы сделали это длинный пост, но я думаю, что должен показать все, чтобы я мог получить правильный ответ на происходящее. Позвольте мне продолжить:

Моя установка - nginx/uwsgi. Вот как я бегу uwsgi помощью выскочку:

description "pycms" 
start on [2345] 
stop on [06] 

respawn 

# start from virtualenv path 
chdir /www/python/apps/pycms/ 

exec uwsgi -b 25000 --chdir=/www/python/apps/pycms --module=wsgi:application --env DJANGO_SETTINGS_MODULE=settings --socket=127.0.0.1:8081 --processes=5 --harakiri=20 --max-requests=5000 --vacuum --master --pidfile=/tmp/pycms-master.pid 

Предполагая, что я прошу следующий API:

http://IP_ADDRESS/api/nodes/mostviewed/9/ 

который соответствует следующему правилу:

url(r'^nodes/mostviewed/(?P<category>\d+)/$', MostViewedNodesList.as_view(), name='mostviewed-nodes-list'), 

Вот вид класса на основе:

class MostViewedNodesList(generics.ListAPIView): 
    """ 
    API endpoint that lists featured nodes 
    """ 
    model = ObjectStats 
    serializer_class = NodeSerializer 
    permission_classes = (permissions.AllowAny,) 

    def get_queryset(self): 
     if(self.kwargs.has_key('category')): 
      category_id = self.kwargs.get('category') 
      return ObjectStats.get_most_viewed(category_id) 
     else: 
      return [] 

Класс сериализатору:

class NodeSerializer(serializers.ModelSerializer): 
    images = ImageSerializer() 
    favorite = ObjectField(source='is_favorite') 
    rating = ObjectField(source='get_rating') 
    meta = ObjectField(source='get_meta') 
    url = ObjectField(source='get_absolute_url') 
    channel_title = ObjectField(source='channel_title') 

    class Meta: 
     model = Node 
     fields = ('id', 'title', 'body', 'images', 'parent', 'type', 'rating', 'meta', 'favorite', 'url', 'channel_title') 

И, наконец, Метод класса «get_most_viewed» (я знаю, что это неправильно использовать методы класса, а не метод менеджера)

@classmethod 
    def get_most_viewed(cls, category_id): 
     return list(Node.objects.extra(
      where=['objects.id=content_api_objectviewsstats.node_id', 'content_api_objectviewsstats.term_id=%s'], 
      params=[category_id], 
      tables=['content_api_objectviewsstats'], 
      order_by=['-content_api_objectviewsstats.num_views'] 
     ).prefetch_related('images', 'objectmeta_set').select_related('parent__parent')) 

Как видно из всего этого, это нормально запрос перенаправляется на указанный вид, извлекает данные из MySQL и затем возвращает сериализованный результат. Ничего необычного или сложной обработки.

Выполнение:

ab -c 500 -n 5000 http://IP_HERE/api/nodes/mostviewed/9/ 

Обратите внимание, что это без кэширования. Ниже часто регистрируются:

HARAKIRI: --- uWSGI worker 5 (pid: 31015) WAS managing request /api/nodes/mostviewed/9/ since Sat Feb 16 13:07:21 2013 --- 
DAMN ! worker 2 (pid: 31006) died, killed by signal 9 :(trying respawn ... 
Respawned uWSGI worker 2 (new pid: 31040) 

нагрузки в среднем во время тестирования идет до ~ 5. И вот результат аб:

Concurrency Level:  500 
Time taken for tests: 251.810 seconds 
Complete requests:  1969 
Failed requests:  1771 
    (Connect: 0, Receive: 0, Length: 1771, Exceptions: 0) 
Write errors:   0 
Non-2xx responses:  1967 
Total transferred:  702612 bytes 
HTML transferred:  396412 bytes 
Requests per second: 7.82 [#/sec] (mean) 
Time per request:  63943.511 [ms] (mean) 
Time per request:  127.887 [ms] (mean, across all concurrent requests) 
Transfer rate:   2.72 [Kbytes/sec] received 

Прежде всего, 7 запросов в секунду очень разочаровывает. ~ 1700 неудачных запросов из-за ошибок таймаута также из-за отставания в производительности, с которым я столкнулся.

Будьте честным. Я ожидаю ~ 60 - 70 запросов в секунду без кэширования. Я знаю, что кеширование ускоряет процесс, но также скрывает проблемы с производительностью, которые у меня есть, и поэтому я преследую эту проблему перед тем, как я кэширую материал. ?

Я решил тогда профиль этого на машине VMware CentOS использования Джанго-профилирования, который путем добавления Prof на запрос показывает стек вызовов:

Instance wide RAM usage 

Partition of a set of 373497 objects. Total size = 65340232 bytes. 
Index Count %  Size % Cumulative % Kind (class/dict of class) 
    0 2270 1 7609040 12 7609040 12 dict of django.db.models.sql.query.Query 
    1 19503 5 6263400 10 13872440 21 dict (no owner) 
    2 63952 17 5739672 9 19612112 30 str 
    3 51413 14 5090344 8 24702456 38 list 
    4 58435 16 4991160 8 29693616 45 tuple 
    5 24518 7 4434112 7 34127728 52 unicode 
    6 8517 2 2384760 4 36512488 56 dict of django.db.models.base.ModelState 
    7 2270 1 2378960 4 38891448 60 dict of django.db.models.query.QuerySet 
    8 2268 1 2376864 4 41268312 63 dict of 0x14d6920 
    9 6998 2 2088304 3 43356616 66 django.utils.datastructures.SortedDict 
<619 more rows. Type e.g. '_.more' to view.> 



CPU Time for this request 

     663425 function calls (618735 primitive calls) in 2.037 CPU seconds 

    Ordered by: cumulative time 

    ncalls tottime percall cumtime percall filename:lineno(function) 
     1 0.000 0.000 2.037 2.037 /usr/lib/python2.6/site-packages/django/views/generic/base.py:44(view) 
     1 0.000 0.000 2.037 2.037 /usr/lib/python2.6/site-packages/django/views/decorators/csrf.py:76(wrapped_view) 
     1 0.000 0.000 2.037 2.037 /usr/lib/python2.6/site-packages/rest_framework/views.py:359(dispatch) 
     1 0.000 0.000 2.036 2.036 /usr/lib/python2.6/site-packages/rest_framework/generics.py:144(get) 
     1 0.000 0.000 2.036 2.036 /usr/lib/python2.6/site-packages/rest_framework/mixins.py:46(list) 
     1 0.000 0.000 2.029 2.029 apps/content_api/views.py:504(get_queryset) 
     1 0.000 0.000 2.029 2.029 apps/objects_stats/models.py:11(get_most_viewed) 
    23/21 0.000 0.000 2.028 0.097 /usr/lib/python2.6/site-packages/django/db/models/query.py:92(__iter__) 
     4/2 0.003 0.001 2.028 1.014 /usr/lib/python2.6/site-packages/django/db/models/query.py:77(__len__) 
     1 0.000 0.000 1.645 1.645 /usr/lib/python2.6/site-packages/django/db/models/query.py:568(_prefetch_related_objects) 
     1 0.002 0.002 1.645 1.645 /usr/lib/python2.6/site-packages/django/db/models/query.py:1596(prefetch_related_objects) 
     2 0.024 0.012 1.643 0.822 /usr/lib/python2.6/site-packages/django/db/models/query.py:1748(prefetch_one_level) 
    2288 0.007 0.000 1.156 0.001 /usr/lib/python2.6/site-packages/django/db/models/manager.py:115(all) 
    6252 0.019 0.000 0.762 0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:231(iterator) 
    4544 0.025 0.000 0.727 0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:870(_clone) 
    4544 0.109 0.000 0.694 0.000 /usr/lib/python2.6/site-packages/django/db/models/sql/query.py:235(clone) 
    2270 0.004 0.000 0.619 0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:619(filter) 
    2270 0.013 0.000 0.615 0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:633(_filter_or_exclude) 
    1144 0.019 0.000 0.581 0.001 /usr/lib/python2.6/site-packages/django/db/models/fields/related.py:456(get_query_set) 
    1144 0.019 0.000 0.568 0.000 /usr/lib/python2.6/site-packages/django/db/models/fields/related.py:560(get_query_set) 
55917/18180 0.192 0.000 0.500 0.000 /usr/lib64/python2.6/copy.py:144(deepcopy) 
    2270 0.003 0.000 0.401 0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:820(using) 

И как вы можете видеть, большая часть времени тратится on django views & Просмотров DRF.

Может ли кто-нибудь указать, что я здесь делаю что-то не так? Почему запросы так медленно?Является ли масштаб python/Django? Я прочитал, что он делает, но сколько запросов/секунд я должен ожидать на простой БД, прочитав операцию рендеринга &, такую ​​как тот, который я делаю?

ответ

2

делает питон/Джанго шкалу на

Django полномочия некоторые довольно массовые услуги, такие как Disqus и Instagram, так что да, это весы просто отлично.

Я решил тогда профиль этого

Как вы можете увидеть почти все время проводится внутри метода .get_most_viewed(), так, что выглядит как вопрос у вас есть. (может быть, не так, но ваш профиль предполагает, что 2.028 из 2.037 времени там тратится, поэтому около 99,6% времени)

Мои навыки ORM на самом деле не в порядке, чтобы выяснить, как именно вы должны иметь дело с этим довольно сложным запросом и в любом случае необходимо будет увидеть определения модели, но вам нужно изучить отладку и упростить этот запрос, а не смотреть на другие части представления.

Возможно, вы захотите зайти в оболочку Django, используя оболочку manage.py, чтобы вы могли профилировать этот конкретный запрос в исключении для остальной части представления.

Также возможно попытаться получить некоторую помощь о том, как можно упростить запрос здесь, или на канал или Джанго список рассылки Django IRC (Вы, вероятно, больше удачи, если вы спросите специально об этом запросе, а не более общие рамки/REST Джанго сформулированы вопрос здесь, большинство из которых на самом деле не кажется, отношение к этому вопросу вашего видения.

Надежда, что помогает направить вас в правильном направлении для получения этого решено.

+0

Спасибо. На самом деле это связано, поскольку кажется, что prefetch_related загружает около 7Mb данных из mysql. Проблема описана здесь: https://github.com/tomchristie/django-rest-framework/issues/656, и вы также можете проверить разговор в списке рассылки restframework с комментарием Ксавьера по этой же проблеме. – Maverick

0

Вы используйте раннее eveluation (например, list (queryset)). Может быть, у вас просто закончилась нехватка памяти, когда многие совладельцы обслуживают ваши запросы? Поэтому вы должны решить: быстро er или больше использования памяти (65 МБ на запрос? это может съесть всю память в секундах)

и профайлер говорит, что ваш код использует QuerySet.all(), который:

Возвращает копию текущего QuerySet (или QuerySet подкласса).

И это вызывает глубокий отпечаток, который требует много времени.

Итак, найдите место, где вызывается all(), и не используйте его.

Смежные вопросы