sexta-feira, 4 de maio de 2012

Performance de web apps Python com Django

E ai pessoal! Tem-se falado muito sobre a performance de aplicações Python e também sobre web apps Python feitas em Django, reflexo da crescente adoção destas tecnologias em projetos cada vez maiores. Meu caso não é diferente, trabalho com Python e Django e, devido as necessidades dos projetos, tenho estudado sobre esse assunto que acho muito interessante. O problema é que cada texto que encontrei tratava de apenas uma abordagem deste tema, seja o deployment, as tecnologias usadas, a arquitetura ou o profiling do código em si. Por isso resolvi escrever este post, uma tentativa de compilar todos estes pontos e criar um material que ajude, de forma geral, a conseguir um melhor desempenho de nossas aplicações.

Vou adotar como estratégia uma abordagem "de fora para dentro", na intenção de começar com fatores externos ao código que podem interferir na performance da aplicação, seguindo com os temas relacionados ao código e como podemos "medir" os mesmos.

Deployment e arquitetura física


Quando falamos de performance ou desempenho de software nos referimos a como um sistema responde quando submetido a uma carga de trabalho. Em uma aplicação web, por exemplo, existem muitas camadas de software envolvidas, o servidor web, a aplicação em si, o banco de dados e etc. Desta forma, todas estas camadas (ou elementos) podem interferir em como o sistema responde.

Sobre este tema existe um post, um pouco antigo mas muito interessante, do Jakob Kaplan-Moss que é um dos criadores do framework Django. Os prontos principais, para nossos fins, são:

Use um servidor separado para arquivos estáticos e outro para o banco de dados. Servir arquivos estáticos de forma dedica reflete na performance da app pois podemos usar um alto grau de cache nestes arquivos e servidores de alto desempenho, como o lighttpd. Se não tiver um servidor físico para isso, use um servidor web para a aplicação e outro para arquivos estáticos. O mesmo se aplica ao banco de dados, que compete com o servidor web por recursos da máquina prejudicando o desempenho da aplicação, por isso use um servidor dedicado ao BD sempre que possível.

Não economize em memória RAM. Dentre os fatores ligados ao hardware que podem impactar no desempenho da aplicação, o mais barato de se resolver é a memória RAM, por isso não seja muquirana! Outro fator é a existência de bancos de dados que rodam exclusivamente em memória RAM o que, obviamente, tem grande impacto no desempenho. Por isso, não poupe nesse caso pois estes bancos in-memory podem ser uma boa opção.

Use um mecanismo de cache. Qualquer aplicação será beneficiada, principalmente se tiver grande volume de leitura. Por isso não invente, procure o melhor mecanismo de cache mas não deixe de estudar sobre Memcached.

Profiling


Agora que falamos de fatores externos que podem comprometer a performance da aplicação, chegou o momento de abordar as ferramentas que podem ajudar na analise do código. Vamos começar do mais simples para os mais avançados:

O Modulo timeit


O modulo timeit, da biblioteca padrão, nos ajuda a determinar o tempo de execução de uma pequena parte de código e assim escolher a melhor opção:

[sourcecode language="python"]
>>> from timeit import Timer
>>> Timer("'d' in lista", "lista = ['a','b','c','d']").timeit()
0.1188361644744873
>>> Timer("'d' in lista", "lista = set( ['a','b','c','d'] )").timeit()
0.07780599594116211
[/sourcecode]

Este exemplo mostra como acessar itens de um set é mais rápido que itens em uma lista, isso porque o set é implementado usando a tabela hash.

O Modulo profile


O modulo profile é totalmente escrito em Python e imita a API de um modulo similar escrito em C, o cProfile, e por este motivo adiciona algum overhead aos testes de performance, mas para nossos fins será muito útil. Certifique-se de ter instalado o pacote python-profiler com o apt-get ou similar.

[sourcecode language="python"]
>>> import profile
>>> from time import sleep
>>> def teste():
... for i in range(10):
...   print i
...     sleep(1)
...

>>> profile.run('teste()')
0
1
2
3
4
5
6
7
8
9
15 function calls in 0.010 CPU seconds

Ordered by: standard name

ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.000 0.000 :0(range)
1 0.000 0.000 0.000 0.000 :0(setprofile)
10 0.010 0.001 0.010 0.001 :0(sleep)
1 0.000 0.000 0.010 0.010 :1(teste)
1 0.000 0.000 0.010 0.010 :1()
0 0.000 0.000 profile:0(profiler)
1 0.000 0.000 0.010 0.010 profile:0(teste())
[/sourcecode]

O exemplo é bem simples, mas serve para mostrar que o gargalo de desempenho no nosso profiling esta nas chamadas de sleep, responsável pelo tempo adicionado a função teste.

Tanto o profile quanto o timeit podem ser usados para qualquer tipo de desenvolvimento Python, seja um web app ou um script local. Por isso recomendo a leitura da documentação das bibliotecas. Agora vamos para situações mais complicadas....

Profiling de Projetos Django


As vezes, em um projeto Django, o que precisamos vai alem de mensurar o tempo de uma função, precisamos de ferramentas que nos ajudem com mais. Uma destas ferramentas chama-se Django Debug Toolbar. Com esta ferramenta instalada no ambiente de desenvolvimento é possível ter acesso de forma muito simples a informações e configurações do seu ambiente. No link do projeto é possível ver a lista de opções e informações de instalação. Dentre as opções disponíveis, existem duas muito interessantes para nossos fins, são elas a inspeção de SQL e de Tempo de CPU.



Nesta tela podemos ver todas as queries executadas pelo Django e analisar quais são as mais custosas e por que.



Nesta outra podemos ver o tempo de execução de cada request, onde:

User CPU time: É o tempo que o navegador levou para renderizar a página.
System CPU time: É o tempo que o servidor levou para enviar a resposta da requisição.
Total CPU time: É o tempo total gasto entre receber e responder por uma  requisição.
Elapsed time: É o tempo desde que o request foi feito
Context switches: São trocas de contextos onde uma thread dorme para esperar algum outro processamento de forma voluntária ou quando é forçada pelo sistema a esperar para que assim outra coisa possa ser processada, involuntariamente.

Com estas duas informações já é possível fazer um bom trabalho de profiling, mas existe um terceiro painel que não vem habilitado por default na ferramenta. Este painel usa o módulo profile (na verdade o cProfile) que acabamos de ver para ter informações da execução da view executada pelo Django e justamente por esse motivo não vem habilitado por padrão. Se reparamos bem no exemplo a cima, percebemos que ao executar o método run de profile a função é executada e sua saída é mostrada no console python. Esta característica pode causar alguns problemas dependendo da view que é executada, já que a mesma será chamada duas vezes e, por isso, o painel vem desabilitado por padrão. Para habilita-lo basta adicionar a seguinte configuração no settings do Django:

[sourcecode language="python"]
DEBUG_TOOLBAR_PANELS = (
'debug_toolbar.panels.version.VersionDebugPanel',
'debug_toolbar.panels.timer.TimerDebugPanel',
'debug_toolbar.panels.settings_vars.SettingsVarsDebugPanel',
'debug_toolbar.panels.headers.HeaderDebugPanel',
'debug_toolbar.panels.request_vars.RequestVarsDebugPanel',
'debug_toolbar.panels.template.TemplateDebugPanel',
'debug_toolbar.panels.sql.SQLDebugPanel',
'debug_toolbar.panels.signals.SignalDebugPanel',
'debug_toolbar.panels.logger.LoggingPanel',
'debug_toolbar.panels.profiling.ProfilingDebugPanel', # Linha responsável por adicionar o painel de Profiling
)
[/sourcecode]

A interface apresentada pelo painel Profiling é como esta:



O Django Debug Toolbar é uma ótima ferramenta mas, e se precisarmos de ainda mais detalhes? Ai chegamos a opção mais completa que encontrei até o momento, a união entre django-extensions e o KCacheGrind. O projeto django-extensions é bem conhecido, mas pouco ouvi falar sobre o seu servidor de profiling até que comecei a pesquisar mais a fundo sobre profiling de apps Django. Este servidor é chamado da mesma forma que o servidor de testes do Django, com a diferença que a cada requisição ele grava um arquivo .prof que pode ser aberto com o KCacheGring para explorar os detalhes do profiling. Depois de instalar o django-extensions, podemos iniciar este servidor da seguinte forma:

[sourcecode language="bash"]
$ python manage.py runprofileserver --kcachegrind --prof-path=/tmp/
Validating models...
0 errors found

Django version 1.4, using settings 'avaliacao.settings'
Development server is running at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
[/sourcecode]

Depois que o servidor estiver rodando, basta navegar na aplicação que os arquivos .prof serão gravados no path indicado. Ao abri-los com o KCacheGrind vemos um interface como esta:



Nesta interface conseguimos ver e navegar em todas as chamadas realizadas no sistema, inclusive nas chamadas realizadas pelo framework, e temos mais informações a respeito de cada camada do sistema, inclusive o tempo de execução de cada chamada. Eu ainda preciso estudar mais esta ferramenta, mas vejo nela a possibilidade de fazer analises bem mais avançadas.

Conclusão


O post ficou um pouco maior do que eu esperava e mesmo assim sei que ainda existe muito o que estudar e aprender sobre esse assunto. Meu objetivo foi compilar em um único material os pontos que venho estudando sobre profiling e melhoria de performance mas vou deixar maiores detalhes para posts futuros.

Sugiro a leitura dos links de referencias para maiores detalhes, já que o post se limita a uma visão geral e apenas mostra alguns caminhos que considero ser os mais adequados.

Espero que tenha gostado do material, mas deixe seu comentário de qualquer forma =D.

Um abraço!

Referencias


http://jacobian.org/writing/django-performance-tips/
http://www.doughellmann.com/PyMOTW/profile/
http://imasters.com.br/artigo/24050/py/dicas-de-desempenho-do-python-parte-01
http://imasters.com.br/artigo/24089/py/dicas-de-desempenho-do-python-parte-02
http://docs.python.org/library/profile.html
http://menendez.com/blog/launching-high-performance-django-site/
http://www.jodal.no/2011/10/19/speeding-up-a-django-web-site-without-touching-the-code/
http://nichol.as/benchmark-of-python-web-servers
https://docs.djangoproject.com/en/1.4/topics/db/optimization/
http://rafaelcaricio.blogspot.com.br/2010/11/deployment-de-django-usando-nginx_05.html

13 comentários:

  1. boa cara.. nao tive tempo de ler tudo mas o assunto eh relevante.. sofremos um pouco com performance no django nos ultimos tempos aqui na bireme..

    parabens.. ;)

    ResponderExcluir
  2. Se precisarem de ajuda me fala cara. Estou estudando bastante o assunto.
    Abraço!

    ResponderExcluir
  3. Ai sim ein! Muito bom o post, parabéns =]

    ResponderExcluir
  4. Obrigado cara! Não me aprofundo muito, mas pretendo ir mais a fundo nos próximos posts. Abraço!

    ResponderExcluir
  5. Estamos desenvolvendo o http://medlist.paho.org .. A comparação de duas listas durava cerca de 45s pra carregar.. utlizamos o django debug toolbar e vimos q eram feitas mais de 3500 queries no banco.. rs .. ai utilizamos o cache do core do django.. diminuimos para 150 queries.. q sao carregadas em +- 2s..

    ResponderExcluir
  6. Ótimo exemplo de profiling e correção cara, show de bola! Vou te dizer que ainda pode melhorar mais fazendo algumas refatorações nos templates e views...

    ResponderExcluir
  7. Dicas muito interessantes e o mais importante úteis. Parabéns

    ResponderExcluir
  8. Nunca consegui utilizar o "ProfilingDebugPanel" da Django Debug Toolbar porque ele um bug que duplica a execução do método "save" em todos os models.

    ResponderExcluir
  9. Arthur, este problema é uma consequência da biblioteca de profile usada, que precisa executar o código a ser analisado (no caso a view) para obter os dados deste profiling. Na verdade, até o momento, eu não conheço uma forma de obter estes dados sem executar o código e, por isso, temos este problema. Minha dica é habilitar este Panel apenas para os casos de exibição dos dados, assim ele não causa problemas. Para os casos em que haverá persistência de dados, eu desabilito o "ProfilingDebugPanel" e uso apenas um logging com o tempo de execução da view.

    Um abraço!

    ResponderExcluir
  10. Opa Sr. Demorei para ler, mas deixei na lista dos "tenho que ler". O post esta bem legal, muito bem escrito. Parabéns.

    ResponderExcluir
  11. Obrigado Sr.!! O post ficou grande mesmo e tinha mais coisas para escrever! Mas ele é apenas uma base, um inicio para este tema que pretendo escrever mais.

    Um abraço!

    ResponderExcluir
  12. Muito bom artigo Rafael!

    ResponderExcluir