Django Rest Framework/Wydajność wydajności Django

Question

Obecnie wdrażam Django w/Django-Rest-Framework na moim małym serwerze instancji EC2, aby zapewnić zestaw interfejsów API dla kilku aplikacji na Androida.

Problem polega na tym, że mam do czynienia z poważnym problemem z wydajnością, który musiałem profilować. Dowiedziałem się, że większość czasu na pojedyncze żądanie spędza się wewnątrz rdzenia DRF.

Przepraszamy za długi wpis, ale myślę, że muszę pokazać wszystko, abym mógł uzyskać właściwą odpowiedź na to, co się dzieje. Pozwól mi iść dalej:

Moja konfiguracja to nginx/uwsgi. Oto jak używam uwsgi użyciu dorobkiewicz:

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 

Zakładając, że żądania następujące API:

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

który pasuje następującą regułę:

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

oto widok klasy w oparciu o:

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 [] 

Klasa serializer:

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') 

I wreszcie classmethod 'get_most_viewed' (wiem, że to jest złe użycie classmethods zamiast metody Manager)

@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')) 

Jak widać z tego wszystkiego, to jest normalne wniosek jest przekierowywany do wyznaczonego widoku, pobieranie danych z MySQL, a następnie zwrot serializowanego wyniku. Nic niezwykłego ani skomplikowane przetwarzanie.

Wykonanie:

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

Zauważ, że jest to bez buforowania. Poniżej znajduje często rejestrowane:

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) 

średnie obciążenie podczas testów podchodzi do ~ 5. A oto wynik AB:

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 

Przede wszystkim, 7 zapytań na sekundę, jest bardzo rozczarowujące. ~ 1700 nieudanych próśb ze względu na błędy przekroczenia limitu czasu wynika również z opóźnienia wydajności, z którym borykam się tutaj.

Szczerze mówiąc. Oczekuję ~ 60 - 70 żądań na sekundę bez buforowania. Wiem, że buforowanie przyspiesza proces, ale także ukrywa problemy z wydajnością, które mam, dlatego staram się rozwiązać ten problem, zanim cache'uje. ?

Postanowiłem wtedy do profilu to na maszynie VMware CentOS użyciu django-profilowanie, które dodając prof do wniosku wykazano stosu wywołań:

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) 

I jak widać, większość czasu spędza na widokach django & Widoki DRF.

Czy ktoś może wskazać, że robię coś nie tak? Dlaczego żądania są takie powolne?Czy skala Pythona/Django? Czytałem, że robi to, ale ile żądań/sekund powinienem oczekiwać na prostej operacji odczytu DB read & takiej jak ta, którą robię?

Answer 1

nie skaluje Python/Django

Django uprawnienia niektóre dość masywne usług, takich jak Disqus i Instagram, więc tak, to skaluje dobrze.

Postanowiłem wtedy do profilu tej

Jak widać prawie cały czas spędza wewnątrz metody .get_most_viewed(), tak, że wygląda w kwestii co masz. (Mogłoby być tam źle, ale twój profil sugeruje, że spędza się tam 2,028 z 2,037 czasu, więc w 99,6% przypadków)

Moje umiejętności ORM nie są tak dokładne, aby dokładnie określić, w jaki sposób powinieneś Zajmuje się tym dość złożonym zapytaniem i musiałby w każdym razie zobaczyć definicje modelu, ale trzeba zajrzeć do debugowania i uprościć to zapytanie, zamiast przyglądać się innym częściom widoku.

Możesz chcieć wpaść do powłoki Django za pomocą powłoki manage.py, dzięki czemu możesz profilować to konkretne zapytanie w wykluczeniu do reszty widoku.

Również może spróbować uzyskanie pomocy w jaki sposób można uprościć zapytania tutaj, lub na kanale lub django liście dyskusyjnej Django IRC (Będziesz prawdopodobnie mieć więcej szczęścia jeśli zapytać specjalnie o tej kwerendy, zamiast bardziej ogólnie Django framework/REST sformułowane pytanie tutaj, większość z których faktycznie nie wydają się być odpowiednie do wystawienia Twój widzenie.

nadzieję, że pomoże wskazać we właściwym kierunku dla coraz to rozwiązane.

Answer 2

Ty użyj wczesnej ewaluacji (np. listy (queryset)) Może po prostu zabraknie Ci pamięci, gdy wielu pracowników współpracujących z serwerem będzie obsługiwać twoje żądania? Musisz więc zdecydować: szybko er wyniki lub więcej pamięci (65 MB na żądanie? to może zjeść całą pamięć w sekundach)

i profiler mówi, że kod wykorzystuje QuerySet.all(), która:

Zwraca kopię bieżącego queryset (lub queryset podklasy).

A to wymaga głębi, która zajmuje dużo czasu.

Znajdź miejsce, w którym wywoływane jest wszystko() i nie używaj go.

Answer 3

Rozmowa była kontynuowana na listę mailingową DRF za https://groups.google.com/forum/?fromgroups=#!topic/django-rest-framework/AkLKdfxCrcU