quarta-feira, 3 de julho de 2013

Desempenho

Programar é fazer escolhas e fazer escolhas boas é acreditar que temos elementos suficientes para tomarmos uma decisão certeira, não é assim que funciona? nem sempre, e muitas vezes nossas escolhas são mais baseadas em experiências bem sucedidas do que efetivamente em análises precisas da situação. Não se culpe, somos todos assim mesmo.

Muitas vezes, talvez a maioria das vezes, as escolhas são realizadas às cegas, não porque queremos, mas porque não temos informações suficientes.  Quanto mais informações tivermos, melhor seria nossa escolha? também é relativo, veja sua esposa, por exemplo, você sabia que ela roncava antes de se casar com ela? se soubesse desse pequeno detalhe, isso influenciaria sua decisão? mas o fato de aprender 'depois' que ela roncava, e pelo fato de ainda estar casado com ela, não significa que você se tornou uma pessoa melhor? mais compreensiva? ou na melhor das hipóteses, que usa aqueles eficientes tampões de ouvido para dormir, rs...

Enfim, divagações a parte, quando falamos em desempenho da aplicação o que temos que fazer é o seguinte, conhecer muito bem o custo x benefício de cada estratégia, e claro, os recursos que temos à nossa disposição. Motivado por perguntas do tipo o que era melhor programar for each de forma tradicional ou com data selector, acabei fazendo um teste que me surpreendeu.

Peguei uma tabela com 1,5 milhão de registros e fiz uma simples operação de contagem, medindo o consumo em milissegundos no tempo da solicitação (refresh no navegador) e a resposta devolvida pelo servidor.  Claro que não utilizei nenhum cronômetro para fazer isso, mas sim o Fiddler, que tem um timeline muito interessante.

Foram três webpanel bastante simples, o primeiro executava a operação de varrer a tabela utilizando um for each tradicional.

(1)
for each
defined by HistoricoData
    &total +=1
endfor

No segundo exemplo substituímos apenas o defined by no for each por um objeto data selector.

(2)

for each
using DataSelector1()
     &total +=1
endfor

Sendo que no DataSelector1 o que 'programamos' foi apenas o defined by, rs..

E o terceiro exemplo, partimos para a ignorância e programamos uma stored procedure direto na base de dados.

(3)
create proc usp_contaregistros @total bigint output
as
select @total=COUNT(HistoricoData) from Historico
return


A intenção? medir a velocidade dos três modelos, e os resultados que obtivemos foi surpreendente, porque o Data Selector teve um desempenho 11% superior ao for each tradicional. Claro que a Stored Procedure teve um desempenho surpreendente sobre o Data Selector 31%, já esperava isso, mas nunca imaginei que o Data Selector tinha um desempenho melhor na programação tradicional Gx.

(1)
for
each
(2)
data
selector
(3)
stored
procedure
1)
265 214 162
2)
277 231 151
3)
226 220 149
4)
238 231 153
media
251,5 224 153,7
11% 31%

Isso nos leva a algumas conclusões:
  1. Se possível atualize seus programas utilizando esse recurso, ou pelo menos faça um teste na sua realidade para comprovar esses dados. Não sei se uma querie mais complexa influenciaria nos resultados
  2. Stored procedure sempre terá um desempenho melhor, e sob este único ponto de vista, claro que sempre ganhará dos demais modelos, mas não se esqueça do problema de manutenção do sistema, que sempre será mais complicado que a programação Genexus tradicional
  3. Existem outros elementos na interface que afetam o desempenho da aplicação, não incorra no erro de pensar que a culpa de tudo é do acesso ao banco de dados
  4. Se desempenho for de fato um problema relevante, pois veja, que a influencia de uma navegação em uma tabela tão gigante foi mínima, o uso desse recurso 'especial' poderia ser justificada, mas sinceramente acho que deve haver alguma solução diferente para o caso.
Enfim, mesmo com esses resultados fico com a programação for each + Data Selector, que tenho buscado incluir em todos os programas, agora com essa medição de desempenho fico ainda mais seguro pra dizer isso, pois a manutenção do sistema fica absurdamente mais rápido com esses recursos.

Agora como nem todos os casos podem ser solucionados desta forma, se tiver que recorrer a recursos mais 'manuais' para ter um Usain Bolt em seu programa, você pode utilizar os External Objects que são ótimos para realizar a conexão.




Se quiser conferir, os valores auferidos são apresentados a seguir.

(1.1)
Request Count: 10
Bytes Sent: 5.913 (headers:5.913; body:0)
Bytes Received: 82.505 (headers:2.321; body:80.184)
ACTUAL PERFORMANCE
------------
Requests started at: 13:28:22.067
Responses completed at: 13:28:23.954
Sequence (clock) duration: 00:00:01.8871080
Aggregate Session duration: 00:00:00.265


(1.2)
Request Count: 10
Bytes Sent: 5.913 (headers:5.913; body:0)
Bytes Received: 8.888 (headers:2.284; body:6.604)
ACTUAL PERFORMANCE
--------------
Requests started at: 13:31:02.161
Responses completed at: 13:31:02.456
Sequence (clock) duration: 00:00:00.2950169
Aggregate Session duration: 00:00:00.277
(1.3)

Request Count: 10
Bytes Sent: 5.913 (headers:5.913; body:0)
Bytes Received: 8.888 (headers:2.284; body:6.604)
ACTUAL PERFORMANCE
--------------
Requests started at: 13:33:04.380
Responses completed at: 13:33:04.651
Sequence (clock) duration: 00:00:00.2710155
Aggregate Session duration: 00:00:00.226
TCP/IP Connect duration: 1ms


(1.4)
Request Count: 10
Bytes Sent: 5.913 (headers:5.913; body:0)
Bytes Received: 8.888 (headers:2.284; body:6.604)
ACTUAL PERFORMANCE
--------------
Requests started at: 13:33:39.050
Responses completed at: 13:33:39.343
Sequence (clock) duration: 00:00:00.2930168
Aggregate Session duration: 00:00:00.238
DNS Lookup time: 1ms


(2.1)
Request Count: 10
Bytes Sent: 5.915 (headers:5.915; body:0)
Bytes Received: 8.893 (headers:2.286; body:6.607)
ACTUAL PERFORMANCE
--------------
Requests started at: 21:25:02.735
Responses completed at: 21:25:02.970
Sequence (clock) duration: 00:00:00.2350134
Aggregate Session duration: 00:00:00.214
 

(2.2)
Request Count: 10
Bytes Sent: 5.915 (headers:5.915; body:0)
Bytes Received: 8.893 (headers:2.286; body:6.607)
ACTUAL PERFORMANCE
--------------
Requests started at: 21:26:16.958
Responses completed at: 21:26:17.235
Sequence (clock) duration: 00:00:00.2770159
Aggregate Session duration: 00:00:00.231
 
(2.3)
Request Count: 10
Bytes Sent: 5.915 (headers:5.915; body:0)
Bytes Received: 8.893 (headers:2.286; body:6.607)
ACTUAL PERFORMANCE
--------------
Requests started at: 21:27:16.887
Responses completed at: 21:27:17.130
Sequence (clock) duration: 00:00:00.2430139
Aggregate Session duration: 00:00:00.220

(2.4)
Request Count: 10
Bytes Sent: 5.915 (headers:5.915; body:0)
Bytes Received: 8.893 (headers:2.286; body:6.607)
ACTUAL PERFORMANCE
--------------
Requests started at: 21:27:47.828
Responses completed at: 21:27:48.129
Sequence (clock) duration: 00:00:00.3010172
Aggregate Session duration: 00:00:00.231
DNS Lookup time: 1ms
 
(3.1) 
Request Count: 10
Bytes Sent: 5.912 (headers:5.912; body:0)
Bytes Received: 8.887 (headers:2.285; body:6.602)
ACTUAL PERFORMANCE
--------------
Requests started at: 22:01:56.474
Responses completed at: 22:01:56.700
Sequence (clock) duration: 00:00:00.2260129
Aggregate Session duration: 00:00:00.162
 
(3.2) 
Request Count: 10
Bytes Sent: 5.912 (headers:5.912; body:0)
Bytes Received: 8.887 (headers:2.285; body:6.602)
ACTUAL PERFORMANCE
--------------
Requests started at: 22:02:27.434
Responses completed at: 22:02:27.643
Sequence (clock) duration: 00:00:00.2090119
Aggregate Session duration: 00:00:00.151
 
(3.3)
Request Count: 10
Bytes Sent: 5.912 (headers:5.912; body:0)
Bytes Received: 8.887 (headers:2.285; body:6.602)
ACTUAL PERFORMANCE
--------------
Requests started at: 22:02:53.429
Responses completed at: 22:02:53.635
Sequence (clock) duration: 00:00:00.2060118
Aggregate Session duration: 00:00:00.149
 
(3.4)
Request Count: 10
Bytes Sent: 5.912 (headers:5.912; body:0)
Bytes Received: 8.887 (headers:2.285; body:6.602)
ACTUAL PERFORMANCE
--------------
Requests started at: 22:03:15.874
Responses completed at: 22:03:16.079
Sequence (clock) duration: 00:00:00.2050117
Aggregate Session duration: 00:00:00.153