Melhorias de performance em código Python já foram assunto de diversos textos neste blog. Já escrevi sobre utilização de [Cython] e [Numba], fiz uma comparação dessas duas tecnologias com Numpy e recentemente publiquei um texto sobre medição de consumo de memória. Neste texto irei tratar novamente de otimização de programas em Python, focando novamente em um exemplo de TRIOSlib (a biblioteca que desenvolvi durante meu doutorado). Uma das operações feitas é a contagem de pontos diferentes de zero em imagens. Já examinamos as diferenças entre Python puro, Cython e Numba neste operação anteriormente e chegamos à conclusão que o desempenho era melhor utilizando Numba e Cython, mas que mesmo os códigos usando Numpy já ofereciam grandes ganhos de desempenho.
Iremos otimizar a função num_samples(win) da classe Imageset (trios.imageset.Imageset). O código da função está abaixo. O código completo do arquivo pode ser visto aqui.
import os.path
import numpy as np
import trios.shortcuts.persistence as p
import collections
class Imageset:
# .....
def num_samples(self, win):
total = 0
for (_, _, m) in p.load_imageset(self, win):
total += len(np.nonzero(m)[0])
return total
# .....
Na TRIOS um Imageset é uma lista de triplas contendo caminhos para imagens. A função num_samples(win) conta quantos pontos brancos existem na terceira imagem da tripla. A função load_imageset() carrega do disco as imagens gravadas em uma tripla e as retorna como matrizes do Numpy. Atualmente estamos usando Numpy para fazer a contagem de pontos.
Diferentemente dos textos anteriores, a função que iremos otimizar neste texto não é somente a implementação de um algoritmo em memória. Imageset.num_samples contém também acessos ao disco, o que significa que uma parte do tempo de execução não depende da implementação da contagem de pontos. Um dos nossos objetivos é verificar se a diferença obtida pela otimização na contagem de pontos é significativa dado o tempo de leitura das imagens do disco.
O módulo cProfile já vem incluso em Python e pode ser usado para medir quanto tempo é gasto por cada função de um programa. Sua utilização não é complicada, mas se torna ainda mais fácil com o módulo profilehooks, que é um wrapper para o cProfile usando o decorador @profile. Basta decorar uma função e um relatório é automaticamente impresso na saída padrão. Também é possível passar várias opções para o decorador.
Nosso código de testes é o seguinte:
from trios import imageset
from profilehooks import profile
import numpy as np
if __name__ == '__main__':
imgset =
imageset.Imageset.read('/media/igor/Data1/datasets/staffs/level1.set')
profiled_num_samples = profile(imgset.num_samples, entries=10)
win = np.ones((11, 11), np.uint8)
print('num_samples:', profiled_num_samples(win))
num_samples: 5595040
*** PROFILER RESULTS ***
num_samples (/home/igor/anaconda3/lib/python3.5/site-packages/trios-2.0.7-py3.5-linux-x86_64.egg/trios/imageset.py:65)
function called 1 times
51097 function calls (50830 primitive calls) in 3.032 seconds
Ordered by: cumulative time, internal time, call count
List reduced from 322 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.003 0.003 3.032 3.032 imageset.py:65(num_samples)
11 0.000 0.000 2.181 0.198 persistence.py:39(load_imageset)
30 0.000 0.000 2.179 0.073 persistence.py:20(load_image)
30 0.000 0.000 2.178 0.073 io.py:22(imread)
30 0.000 0.000 2.178 0.073 pilutil.py:103(imread)
30 0.000 0.000 2.148 0.072 pilutil.py:203(fromimage)
30 0.057 0.002 2.148 0.072 {built-in method numpy.core.multiarray.array}
30 0.001 0.000 2.090 0.070 Image.py:618(__array_interface__)
30 0.005 0.000 2.089 0.070 Image.py:654(tobytes)
30 0.008 0.000 1.968 0.066 ImageFile.py:120(load)
A execução da função num_samples com um conjunto de imagens contendo 10 imagens de alta resolução demorou 3 segundos, sendo que 2.2 segundos foram gastos na função load_imageset. Logo, por mais que otimizemos a contagem de pontos brancos, a execução demorará ao menos o tempo de ler as imagens do disco. Ou seja, mesmo para imagens em alta resolução uma pequena parte (cerca de 25%) do tempo é gasta contando os pontos brancos. Se possível, otimizar a leitura das imagens traria ganhos mais significativos.
A coluna ncalls mostra o número de vezes que a função daquela linha foi chamada, enquanto cumtime mostra o tempo cumulativo de execução (ou seja, o tempo da função executar por completo). Apesar de estarmos carregando somente 10 imagens p.load_image foi chamada 30 vezes! Examinando o código da função p.load_imageset vemos que ela retorna 3 imagens, mas só usamos a máscara. Logo, se lermos somente a máscara do disco poderemos economizar bastante tempo.
O novo código da função num_samples é
def num_samples(self, win):
total = 0
for (i, o, m) in self:
if m is not None:
m = p.load_mask_image(m, None, win)
total += len(np.nonzero(m)[0])
else:
i = p.load_image(i)
ww = win.shape[1]
wh = win.shape[0]
total += (i.shape[0] - wh+1)*(i.shape[1] - ww+1)
return total
num_samples: 5595040
*** PROFILER RESULTS ***
num_samples2 (/home/igor/Dropbox/blog/otimizacao-trios/imageset.py:71)
function called 1 times
22088 function calls (21821 primitive calls) in 1.618 seconds
Ordered by: cumulative time, internal time, call count
List reduced from 321 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.003 0.003 1.618 1.618 imageset.py:71(num_samples2)
10 0.000 0.000 0.857 0.086 fromnumeric.py:1490(nonzero)
10 0.856 0.086 0.856 0.086 {method 'nonzero' of 'numpy.ndarray' objects}
10 0.002 0.000 0.758 0.076 persistence.py:23(load_mask_image)
10 0.000 0.000 0.756 0.076 persistence.py:20(load_image)
10 0.000 0.000 0.756 0.076 io.py:22(imread)
10 0.000 0.000 0.756 0.076 pilutil.py:103(imread)
10 0.000 0.000 0.732 0.073 pilutil.py:203(fromimage)
10 0.016 0.002 0.732 0.073 {built-in method numpy.core.multiarray.array}
10 0.001 0.000 0.716 0.072 Image.py:618(__array_interface__)
O consumo de tempo foi reduzido pela metade! Isto mostra a grande importância de medir qual função/parte de um script consome mais tempo. Podemos otimizar somente as partes que gastam a maior parte do tempo e identificar quais otimizações valem a pena. Além disto, agora a operação mais cara realmente é a contagem de pontos (linha 2, função nonzero em numeric.py). Mudando a contagem de pontos para a função np.count_nonzero obtemos a seguinte medição de tempo.
num_samples: 5595040
*** PROFILER RESULTS ***
num_samples3 (/home/igor/Dropbox/blog/otimizacao-trios/imageset.py:84)
function called 1 times
22068 function calls (21801 primitive calls) in 1.073 seconds
Ordered by: cumulative time, internal time, call count
List reduced from 320 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.004 0.004 1.073 1.073 imageset.py:84(num_samples3)
10 0.002 0.000 0.766 0.077 persistence.py:23(load_mask_image)
10 0.000 0.000 0.765 0.076 persistence.py:20(load_image)
10 0.000 0.000 0.765 0.076 io.py:22(imread)
10 0.000 0.000 0.764 0.076 pilutil.py:103(imread)
10 0.000 0.000 0.743 0.074 pilutil.py:203(fromimage)
10 0.019 0.002 0.743 0.074 {built-in method numpy.core.multiarray.array}
10 0.001 0.000 0.723 0.072 Image.py:618(__array_interface__)
10 0.002 0.000 0.723 0.072 Image.py:654(tobytes)
10 0.003 0.000 0.662 0.066 ImageFile.py:120(load)
Diminuimos a execução de 3 segundos no primeiro exemplo para somente 1 segundo. Executar as funções com @profile nos ajudou a encontrar onde a função gastava a maior quantidade de tempo e fizemos pequenas mudanças adicionais para ganhar ainda mais performance. É possível ir ainda mais longe, como pudemos ver no comparativo Numpy x Numba x Cython, porém o ganho de desempenho será pequeno para nosso caso de uso. É mais vantajoso manter o código mais enxuto e simples do que adicionar complexidade e dependências por um ganho pequeno. O código final da função é mostrado abaixo.
def num_samples3(self, win):
total = 0
for (i, o, m) in self:
if m is not None:
m = p.load_mask_image(m, None, win)
total += np.count_nonzero(m)
else:
i = p.load_image(i)
ww = win.shape[1]
wh = win.shape[0]
total += (i.shape[0] - wh+1)*(i.shape[1] - ww+1)
return total
Espero que este texto tenha mostrado a importância da utilização de ferramentes de profiling para medição de tempo de execução em Python. Muitos scripts podem ser otimizados de maneira inteligente se nos concentrarmos somente nas partes que demoram a maior parte do tempo.
Nenhum comentário:
Postar um comentário