Upgrade to Pro — share decks privately, control downloads, hide ads and more …

Debugging Performance with Django by Aymeric Au...

Debugging Performance with Django by Aymeric Augustin

Django: Under The Hood

November 04, 2016
Tweet

More Decks by Django: Under The Hood

Other Decks in Programming

Transcript

  1. debugging performance Django: Under the Hood November 3rd, 2016 Aymeric

    Augustin Festival international des jardins, Chaumont, 8 mai 2015
  2. I’m Aymeric Core Developer since 2011 Freelancing since 2015 •

    Time zones • Python 3 • Transactions • App loading • Jinja2 Consulting on Django, big data, &
 architecture
  3. I’m Aymeric Core Developer since 2011 Founder & CTO since

    2015 • Time zones • Python 3 • Transactions • App loading • Jinja2 First collaborative insurance broker in France https://otherwise.fr/ [FR]
  4. Perception of response time • fast = up to 0.1s

    = reacting instantaneously • just display the result • normal = up to 1s = not interrupting the user's flow of thought • user will notice the delay but no feedback is necessary • slow = up to 10s = keeping the user's attention focused • feedback is important, especially if response time is unpredictable Source: https://www.nngroup.com/articles/website-response-times/
  5. In production • Google Chrome Developer Tools • only affects

    the network • Google Analytics Site Speed • sampled on 1% of users by default • Application Performance Monitoring solutions
  6. Performance timeline redirects app cache DNS TCP request response processing

    on load navigationStart redirectStart redirectEnd fetchStart dom ainLookupStart dom ainLookupEnd connectStart secureC onnectionStart connectEnd requestStart responseStart responseEnd dom Loading dom Interactive dom C ontentLoadedEventStart dom C om plete loadEventStart loadEventEnd unloadEventStart unloadEventEnd dom C ontentLoadedEventEnd Did you expect requestEnd?
  7. HTTP/1.1 is bad at fetching many resources • Client-side •

    DNS pre-fetch • TCP pre-connect • keep-alive & pipelining • parallel connections • caching • Server-side • concatenation • spriting • inlining • domain sharding • allow caching
  8. Performance timeline redirects app cache DNS TCP request response processing

    on load navigationStart redirectStart redirectEnd fetchStart dom ainLookupStart dom ainLookupEnd connectStart secureC onnectionStart connectEnd requestStart responseStart responseEnd dom Loading dom Interactive dom C ontentLoadedEventStart dom C om plete loadEventStart loadEventEnd unloadEventStart unloadEventEnd dom C ontentLoadedEventEnd Did you expect requestEnd?
  9. document.readyState & page load events • domLoading • No event


    (no JS yet!) • Parse HTML
 & build DOM • Download &
 run sync JS • domInteractive • DOMContent- Loaded event • Download
 CSS & images • Parse CSS &
 build CSSOM • domComplete • load event
 • Page is fully loaded ‘loading’ ‘interactive’ ‘complete’
  10. document.readyState & page load events dom Loading dom Interactive dom

    C om plete DO M C ontent-
 Loaded event load event
  11. CSS

  12. JS

  13. Critical path - text edition • Rendering a page requires

    a DOM and a CSSOM • Download and parse HTML • Download and parse CSS • Building the DOM blocks on sync JS • Download and execute sync JS • Executing JS blocks on the CSSOM • Wait until CSS is parsed to execute sync JS
  14. Browsers optimize heavily page load time • Parse HTML incrementally

    • Paint while waiting for sync JS • After CSS is available • Paint while waiting for web fonts • With a default font — browser dependent • Preload scanner
  15. Guidelines 1. Optimize HTML load time 2. Optimize CSS load

    time • Unblock first paint • Avoid blocking JS execution 3. Avoid sync JS, including inline JS, or put it at the bottom • Avoid blocking DOM construction • Trigger DOMContentLoaded as early as possible
  16. “The JavaScript tracking snippet” <!-- Google Analytics --> <script> (function(i,s,o,g,r,a,m)

    {i['GoogleAnalyticsObject']=r;i[r]=i[r]||function() {(i[r].q=i[r].q||[]).push(arguments)},i[r].l=1*new Date();a=s.createElement(o),m=s.getElementsByTagName(o) [0];a.async=1;a.src=g;m.parentNode.insertBefore(a,m)}) (window,document,'script','https://www.google- analytics.com/analytics.js','ga'); ga('create', 'UA-XXXXX-Y', 'auto'); ga('send', 'pageview'); </script> <!-- End Google Analytics --> https://developers.google.com/analytics/devguides/collection/analyticsjs/
  17. Script-injected scripts window.GoogleAnalyticsObject = 'ga' window.ga = window.ga || function

    () { window.ga.q = window.ga.q || [] window.ga.q.push(arguments) } window.ga.l = 1 * new Date() var script = document.createElement('script') script.async = 1 script.src = \ 'https://www.google-analytics.com/analytics.js' var otherScript = \ document.getElementsByTagName('script')[0] otherScript.parentNode.insertBefore(script, otherScript)
  18. “Alternative async tracking snippet” <!-- Google Analytics --> <script> window.ga=window.ga||function(){(ga.q=ga.q||

    []).push(arguments)};ga.l=+new Date; ga('create', 'UA-XXXXX-Y', 'auto'); ga('send', 'pageview'); </script> <script async src='https://www.google-analytics.com/ analytics.js'></script> <!-- End Google Analytics --> https://developers.google.com/analytics/devguides/collection/analyticsjs/
  19. Async scripts window.ga = window.ga || function () { ga.q

    = ga.q || [] ga.q.push(arguments) } ga.l = +new Date // plus an async script: <script async src='https://www.google-analytics.com/ analytics.js'></script>
  20. New best practice? <html> <head> <script> /* Async function queuing

    */ </script> <link rel="stylesheet" href="style.css"> <script async src="critical.js"></script> <style> /* For above-the-fold content */ </style> </head> <body> <script async src="non-critical.js"></script> </body> </html>
  21. Request-response cycle request URL view tmpl. resp. response middleware view


    mw. t. r.
 mw. exc.
 mw. request_started request_finished middleware
  22. pgbench (1/2) $ pgbench -i --foreign-keys duth16dp creating tables... 100000

    of 100000 tuples (100%) done (elapsed 0.11 s, remaining 0.00 s) vacuum... set primary keys... set foreign keys... done.
  23. pgbench (2/2) $ pgbench -c 30 -T 180 duth16dp starting

    vacuum...end. transaction type: TPC-B (sort of) scaling factor: 1 query mode: simple number of clients: 30 number of threads: 1 duration: 180 s number of transactions actually processed: 313568 latency average: 17.221 ms tps = 1741.538334 (including connections establishing) tps = 1741.569697 (excluding connections establishing)
  24. Sprint idea • Figure out if pathological performance of LEFT

    OUTER JOIN vs. INNER JOIN still happens these days • Make the case for treating FKs identically in select_related regardless of whether they’re nullable • Many projects would benefit from a default select_related that includes nullable FKs in the admin • Think about backwards compatibility — no easy answer there • Search: “site:code.djangoproject.com select_related nullable”
  25. Prefetch objects • Prefetch(lookup, queryset=None, to_attr=None) • Specify a relation

    to follow • Can filter, order, etc. the target queryset • Required to filter, order, etc. prefetched querysets • Can attach the result to an attribute with another name • Recommended when the target queryset is filtered
  26. select_related() vs. prefetch_related() • “Generally you’ll want to use select_related()”

    • It’s more elegant but it isn’t always faster • select_related() fetches more data • Consequences depend on the database schema and content • prefetch_related() makes several queries • Transactional consistency isn’t guaranteed (#27403) • Depends mostly on the latency of database queries
  27. select_related() vs. prefetch_related() from pgbench.models import Transaction transactions = Transaction.objects.all()

    # Many distinct related objects transactions.select_related('account') # Database = 1.32s - Total = 11.4s transactions.prefetch_related('account') # Database = 0.62s + 0.58s = 1s - Total = 14.5s (+26%)
  28. select_related() vs. prefetch_related() from pgbench.models import Transaction transactions = Transaction.objects.all()

    # Few distinct related objects transactions.select_related('teller') # Database = 0.87s - Total = 12.6s transactions.prefetch_related('teller') # Database = 0.66s + ~0s = 0.66s - Total = 12.3s (-2.4%)
  29. Log database queries to the console LOGGING = { 'version':

    1, 'disable_existing_loggers': False, 'handlers': { 'console': { 'class': 'logging.StreamHandler', }, }, 'loggers': { 'django.db.backends': { 'handlers': ['console'], 'level': 'DEBUG', }, }, }
  30. Baseline from collections import defaultdict balances = defaultdict(lambda: 0) from

    pgbench.models import Transaction txs = Transaction.objects.all() for tx in txs: balances[tx.teller_id] += tx.delta # Database = 630ms - Total = 6900ms
  31. only() and defer() from collections import defaultdict balances = defaultdict(lambda:

    0) from pgbench.models import Transaction txs = Transaction.objects.only('teller_id', 'delta') for tx in txs: balances[tx.teller_id] += tx.delta # Database = 220ms (-65%) - Total = 7900ms (+15%)
  32. Use only() or defer() when… • you need model instances

    • you don’t need all columns • especially columns containing large amounts of data • Not a common use case • Consider moving rarely needed data to a separate model
  33. values_list() and values() from collections import defaultdict balances = defaultdict(lambda:

    0) from pgbench.models import Transaction txs = Transaction.objects.values_list('teller_id', 'delta') for teller_id, delta in txs: balances[teller_id] += delta # Database = 160ms (-75%) - Total = 550ms (-92%)
  34. Use values_list() or values() when… • you don’t need model

    instances • you need to manipulate large amounts of data • large starts between 1 000 and 10 000 rows :-( • Common use case: reports • Huge, easy improvement for queries that return lots of rows
  35. aggregate() and annotate() from django.db.models import Sum from pgbench.models import

    Transaction balances = dict( Transaction.objects .values_list('teller_id') .annotate(Sum('delta')) ) # Database = 75ms (-88%) - Total = 77ms (-99%)
  36. Use aggregate() or annotate() when… • you can perform a

    calculation in the database • you need to manipulate large amounts of data • large starts between 1 000 and 10 000 rows :-( • Common use case: dashboards • There’s a learning curve
  37. iterator() • Iterates over instances • Doesn’t cache results •

    Not a common use case • The whole dataset is still fetched from the database at once • Live references to instances still prevent garbage collection
  38. Baseline txs = Transaction.objects.all() import tracemalloc tracemalloc.start() for tx in

    txs: balances[tx.teller_id] += tx.delta tracemalloc.get_traced_memory() # (166775984, 166824045) => current: 159MB, peak: 159MB
  39. iterator() txs = Transaction.objects.iterator() import tracemalloc tracemalloc.start() for tx in

    txs: balances[tx.teller_id] += tx.delta tracemalloc.get_traced_memory() # (187159, 234230) => current: 183kB, peak: 229kB