Performans Ölçümü - Erdinç Uzun

Öncelikle Yüksek Lisans öğrencim “Halil İbrahim Göfer”e teşekkürler. Bu bölümde Python ortamında performans ölçümünü nasıl yapacağımızı göreceğiz.

Performans ölçümü, bazı kodların performansıyla ilgili bilgilerin toplanması ve anlaşılması sürecidir. Performans ölçümleri ilgili başlıca aşağıdaki modüller bulunmaktadır.

timeit
cProfile
pstats
memory_profiler
line_profiler

1. Timeit

Timeit modülü ile başlayacağım. Bu modül, küçük kod parçalarının zamanını belirlememizi sağlar.

import timeit

res1 = timeit.timeit('''
a = [i for i in range(50000)]
for i in a:
    pass
''', number = 100)

res2 = timeit.timeit('''
a = (i for i in range(50000))
for i in a:
    pass
''', number = 100)

print(res1)
print(res2)

import timeit

res1 = timeit.timeit('''

a = [i for i in range(50000)]

for i in a:

pass

''', number = 100)

res2 = timeit.timeit('''

a = (i for i in range(50000))

for i in a:

pass

''', number = 100)

print(res1)

print(res2)

0.26830113399955735
0.3227190840007097

1 2	0.26830113399955735 0.3227190840007097

Timeit.timeit (args) çalışması, verilen kodu yürütmek için geçen süreyi temsil eden bir sonuç döndürür. Yukarıdaki örnekte, ilk argüman yürütülecek koddur ve ikinci argüman kodun kaç kez çalıştırılması gerektiğidir. Kodu birden çok kez çalıştırmak ve ortalamayı almak, tek bir seferde çalıştırılmasından daha doğru bir sonuç verir.

İlginç bir şekilde, yukarıdaki örnek aynı zamanda liste anlamalarının bir dizi değer üzerinde yineleme yapmak için jeneratör ifadeleri kullanmaktan daha hızlı olduğunu, ancak bellek tüketiminin yukarıdaki örnekte bulunmayan daha yüksek olduğunu göstermektedir.

Yukarıdaki kod parçalarını direkt timeit fonksiyonu içinde çalıştırdık. Bu kodları fonksiyonlara çevirip, timeit bölümünden fonksiyonu da çağırabiliriz.

2. CProfile & pstats

CProfile modülü bir python programının deterministik profilini sağlar. CProfile.run (func_name, output_file_name) çağrıldığında verilen işlev görüntülenir ve çıktıyı belirtilen bir dosyaya yazar. Aşağıdakiler çıktıya dahil edilir:

ncalls : aramaların sayısı için
tottime : Verilen fonksiyonda harcanan toplam süre (ve alt fonksiyonlara yapılan çağrılarda zaman hariç)
percall : oplam zamanın ncalls tarafından bölünme
cumtime : Bu ve tüm alt işlevlerde harcanan kümülatif zamandır (başlangıçtan çıkışa kadar). Bu rakam özyinelemeli işlevler için bile doğrudur
percall : İlkel çağrılar ile bölünmüş kümülatif zamanın bir bölümüdür
filename:lineno(function) : her fonksiyonun ilgili verilerini sağlar

Pstats.Stats sınıfı, profilli verileri okumak ve sonuçları gerektiği gibi biçimlendirmek için kullanılır. Aşağıdaki örnek profiller to_be_profiled () ve profil verilerini cprofile_results adlı dosyaya yazar. Pstats.Stats sınıfı daha sonra yaygın olarak kullanılan biçimlerde profil sonuçlarını biçimlendirmek için kullanılır (programdaki yorumları kontrol ediniz).

import cProfile
import pstats
import time
import sys

def to_be_profiled():
    my_list1 = [i**2 for i in range(50000)]

    my_list2 = (i**2 for i in range(100000, 150000))

    sum = 0

    print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))
    print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))

    for i in my_list2:
        sum += i
        time.sleep(0.00001)
        my_list1.append(i)
    print(sum)

cProfile.run('to_be_profiled()', 'cprofile_results')

p = pstats.Stats('cprofile_results')
#sort by standard name
p.strip_dirs().sort_stats(-1).print_stats(10)
#sort by function name
p.sort_stats('name').print_stats(10)
#sort by cumulative time in a function
p.sort_stats('cumulative').print_stats(10)
#sort by time spent in a function
p.sort_stats('time').print_stats(10)

import cProfile

import pstats

import time

import sys

def to_be_profiled():

my_list1 = [i**2 for i in range(50000)]

my_list2 = (i**2 for i in range(100000, 150000))

sum = 0

print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))

print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))

for i in my_list2:

sum += i

time.sleep(0.00001)

my_list1.append(i)

print(sum)

cProfile.run('to_be_profiled()', 'cprofile_results')

p = pstats.Stats('cprofile_results')

#sort by standard name

p.strip_dirs().sort_stats(-1).print_stats(10)

#sort by function name

p.sort_stats('name').print_stats(10)

#sort by cumulative time in a function

p.sort_stats('cumulative').print_stats(10)

#sort by time spent in a function

p.sort_stats('time').print_stats(10)

my_list1 = 406496 bytes
my_list2 = 88 bytes
791660416675000
Sat Dec  3 21:23:38 2016    cprofile_results

         150013 function calls in 3.580 seconds

   Ordered by: standard name
   List reduced from 11 to 10 due to restriction <10>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.002    0.002    3.580    3.580 <string>:1(<module>)
        1    0.117    0.117    3.578    3.578 performance.py:23(to_be_profiled)
        1    0.014    0.014    0.014    0.014 performance.py:24(<listcomp>)
    50001    0.078    0.000    0.078    0.000 performance.py:26(<genexpr>)
        1    0.000    0.000    3.580    3.580 {built-in method builtins.exec}
        3    0.001    0.000    0.001    0.000 {built-in method builtins.print}
        2    0.000    0.000    0.000    0.000 {built-in method sys.getsizeof}
    50000    3.357    0.000    3.357    0.000 {built-in method time.sleep}
    50000    0.011    0.000    0.011    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}


Sat Dec  3 21:23:38 2016    cprofile_results

         150013 function calls in 3.580 seconds

   Ordered by: function name
   List reduced from 11 to 10 due to restriction <10>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    3.580    3.580 {built-in method builtins.exec}
        3    0.001    0.000    0.001    0.000 {built-in method builtins.print}
        2    0.000    0.000    0.000    0.000 {built-in method sys.getsizeof}
    50000    3.357    0.000    3.357    0.000 {built-in method time.sleep}
    50001    0.078    0.000    0.078    0.000 performance.py:26(<genexpr>)
        1    0.014    0.014    0.014    0.014 performance.py:24(<listcomp>)
    50000    0.011    0.000    0.011    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        2    0.000    0.000    0.000    0.000 {method 'format' of 'str' objects}
        1    0.002    0.002    3.580    3.580 <string>:1(<module>)

Sat Dec  3 21:23:38 2016    cprofile_results

         150013 function calls in 3.580 seconds

   Ordered by: cumulative time
   List reduced from 11 to 10 due to restriction <10>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    3.580    3.580 {built-in method builtins.exec}
        1    0.002    0.002    3.580    3.580 <string>:1(<module>)
        1    0.117    0.117    3.578    3.578 performance.py:23(to_be_profiled)
    50000    3.357    0.000    3.357    0.000 {built-in method time.sleep}
    50001    0.078    0.000    0.078    0.000 performance.py:26(<genexpr>)
        1    0.014    0.014    0.014    0.014 performance.py:24(<listcomp>)
    50000    0.011    0.000    0.011    0.000 {method 'append' of 'list' objects}
        3    0.001    0.000    0.001    0.000 {built-in method builtins.print}
        2    0.000    0.000    0.000    0.000 {built-in method sys.getsizeof}
        2    0.000    0.000    0.000    0.000 {method 'format' of 'str' objects}

Sat Dec  3 21:23:38 2016    cprofile_results

         150013 function calls in 3.580 seconds

   Ordered by: internal time
   List reduced from 11 to 10 due to restriction <10>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    50000    3.357    0.000    3.357    0.000 {built-in method time.sleep}
        1    0.117    0.117    3.578    3.578 performance.py:23(to_be_profiled)
    50001    0.078    0.000    0.078    0.000 performance.py:26(<genexpr>)
        1    0.014    0.014    0.014    0.014 performance.py:24(<listcomp>)
    50000    0.011    0.000    0.011    0.000 {method 'append' of 'list' objects}
        1    0.002    0.002    3.580    3.580 <string>:1(<module>)
        3    0.001    0.000    0.001    0.000 {built-in method builtins.print}
        1    0.000    0.000    3.580    3.580 {built-in method builtins.exec}
        2    0.000    0.000    0.000    0.000 {built-in method sys.getsizeof}
        2    0.000    0.000    0.000    0.000 {method 'format' of 'str' objects}

my_list1 = 406496 bytes

my_list2 = 88 bytes

791660416675000

Sat Dec 3 21:23:38 2016 cprofile_results

150013 function calls in 3.580 seconds

Ordered by: standard name

List reduced from 11 to 10 due to restriction <10>

ncalls tottime percall cumtime percall filename:lineno(function)

1 0.002 0.002 3.580 3.580 <string>:1(<module>)

1 0.117 0.117 3.578 3.578 performance.py:23(to_be_profiled)

1 0.014 0.014 0.014 0.014 performance.py:24(<listcomp>)

50001 0.078 0.000 0.078 0.000 performance.py:26(<genexpr>)

1 0.000 0.000 3.580 3.580 {built-in method builtins.exec}

3 0.001 0.000 0.001 0.000 {built-in method builtins.print}

2 0.000 0.000 0.000 0.000 {built-in method sys.getsizeof}

50000 3.357 0.000 3.357 0.000 {built-in method time.sleep}

50000 0.011 0.000 0.011 0.000 {method 'append' of 'list' objects}

1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}

Sat Dec 3 21:23:38 2016 cprofile_results

150013 function calls in 3.580 seconds

Ordered by: function name

List reduced from 11 to 10 due to restriction <10>

ncalls tottime percall cumtime percall filename:lineno(function)

1 0.000 0.000 3.580 3.580 {built-in method builtins.exec}

3 0.001 0.000 0.001 0.000 {built-in method builtins.print}

2 0.000 0.000 0.000 0.000 {built-in method sys.getsizeof}

50000 3.357 0.000 3.357 0.000 {built-in method time.sleep}

50001 0.078 0.000 0.078 0.000 performance.py:26(<genexpr>)

1 0.014 0.014 0.014 0.014 performance.py:24(<listcomp>)

50000 0.011 0.000 0.011 0.000 {method 'append' of 'list' objects}

1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}

2 0.000 0.000 0.000 0.000 {method 'format' of 'str' objects}

1 0.002 0.002 3.580 3.580 <string>:1(<module>)

Sat Dec 3 21:23:38 2016 cprofile_results

150013 function calls in 3.580 seconds

Ordered by: cumulative time

List reduced from 11 to 10 due to restriction <10>

ncalls tottime percall cumtime percall filename:lineno(function)

1 0.000 0.000 3.580 3.580 {built-in method builtins.exec}

1 0.002 0.002 3.580 3.580 <string>:1(<module>)

1 0.117 0.117 3.578 3.578 performance.py:23(to_be_profiled)

50000 3.357 0.000 3.357 0.000 {built-in method time.sleep}

50001 0.078 0.000 0.078 0.000 performance.py:26(<genexpr>)

1 0.014 0.014 0.014 0.014 performance.py:24(<listcomp>)

50000 0.011 0.000 0.011 0.000 {method 'append' of 'list' objects}

3 0.001 0.000 0.001 0.000 {built-in method builtins.print}

2 0.000 0.000 0.000 0.000 {built-in method sys.getsizeof}

2 0.000 0.000 0.000 0.000 {method 'format' of 'str' objects}

Sat Dec 3 21:23:38 2016 cprofile_results

150013 function calls in 3.580 seconds

Ordered by: internal time

List reduced from 11 to 10 due to restriction <10>

ncalls tottime percall cumtime percall filename:lineno(function)

50000 3.357 0.000 3.357 0.000 {built-in method time.sleep}

1 0.117 0.117 3.578 3.578 performance.py:23(to_be_profiled)

50001 0.078 0.000 0.078 0.000 performance.py:26(<genexpr>)

1 0.014 0.014 0.014 0.014 performance.py:24(<listcomp>)

50000 0.011 0.000 0.011 0.000 {method 'append' of 'list' objects}

1 0.002 0.002 3.580 3.580 <string>:1(<module>)

3 0.001 0.000 0.001 0.000 {built-in method builtins.print}

1 0.000 0.000 3.580 3.580 {built-in method builtins.exec}

2 0.000 0.000 0.000 0.000 {built-in method sys.getsizeof}

2 0.000 0.000 0.000 0.000 {method 'format' of 'str' objects}

3. memory_profiler & line_profiler

Bir işlevin satırdaki hat profilini görmek için memory_profiler kullanılır. İçe aktarma, memory_profiler içe aktarma profilinden kullanılarak yapılır. Hangi işlevin bellek profili olması gerektiğini belirtmek için @profile dekoratörünü kullanın.

import sys
import cProfile
from memory_profiler import profile

@profile()
def mem_to_be_profiled():
    
    my_list1 = [i**2 for i in range(50000)]

    my_list2 = (i**2 for i in range(100000, 150000))

    sum = 0

    print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))
    print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))

    for i in my_list2:
        sum += i
        my_list1.append(i)
    print(sum)

mem_to_be_profiled()

import sys

import cProfile

from memory_profiler import profile

@profile()

def mem_to_be_profiled():

my_list1 = [i**2 for i in range(50000)]

my_list2 = (i**2 for i in range(100000, 150000))

sum = 0

print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))

print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))

for i in my_list2:

sum += i

my_list1.append(i)

print(sum)

mem_to_be_profiled()

my_list1 = 406496 bytes
my_list2 = 88 bytes
791660416675000
Filename: mem.py

Line #    Mem usage    Increment   Line Contents
================================================
     5     30.4 MiB      0.0 MiB   @profile()
     6                             def mem_to_be_profiled():
     7
     8     32.1 MiB      1.7 MiB       my_list1 = [i**2 for i in range(50000)]
     9
    10     34.8 MiB      2.7 MiB       my_list2 = (i**2 for i in range(100000, 150000))
    11
    12     32.1 MiB     -2.7 MiB       sum = 0
    13
    14     32.1 MiB      0.0 MiB       print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))
    15     32.1 MiB      0.0 MiB       print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))
    16
    17     34.8 MiB      2.7 MiB       for i in my_list2:
    18     34.8 MiB      0.0 MiB           sum += i
    19     34.8 MiB      0.0 MiB           my_list1.append(i)
    20     34.8 MiB      0.0 MiB       print(sum)

my_list1 = 406496 bytes

my_list2 = 88 bytes

791660416675000

Filename: mem.py

Line # Mem usage Increment Line Contents

================================================

5 30.4 MiB 0.0 MiB @profile()

6 def mem_to_be_profiled():

8 32.1 MiB 1.7 MiB my_list1 = [i**2 for i in range(50000)]

10 34.8 MiB 2.7 MiB my_list2 = (i**2 for i in range(100000, 150000))

12 32.1 MiB -2.7 MiB sum = 0

14 32.1 MiB 0.0 MiB print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))

15 32.1 MiB 0.0 MiB print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))

17 34.8 MiB 2.7 MiB for i in my_list2:

18 34.8 MiB 0.0 MiB sum += i

19 34.8 MiB 0.0 MiB my_list1.append(i)

20 34.8 MiB 0.0 MiB print(sum)

Zamana karşı bellek kullanımı grafiği çiziliyor. Bunun için mprofexecutable kullanacağız. Komut dosyasını çalıştırın ve bellek profili verilerini toplayın:

mprof run mem.py

Yukarıdaki komut, sonucu geçerli dizinde bir dosyada saklar. Zamana göre bellek kullanımı grafiğini çizin:

mprof plot

Yukarıdaki komut, en son oluşturulan bellek profili verilerini kullanır. Çıkış ekran görüntüsü:

Profillendirilmesi gereken işlevi belirtmek için @profile dekoratörünü kullanın. Python dosyasını doğrudan çalıştırarak script.py, @profile tanımlanmadığından bir hata atar, İşlevin satır satır profilini görmek için şunu kullanın:

kernprof -l -v line.py

Bu sorunu aşmanın ve kernprof kullanarak profil oluşturmanın yanı sıra normal bir betik olarak çalıştırmanın yolları vardır. İşte bir Stackoverflow cevabı:

import sys

@profile
def to_be_profiled():
    
    my_list1 = [i**2 for i in range(50000)]

    my_list2 = (i**2 for i in range(100000, 150000))
    sum = 0
    print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))
    print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))

    for i in my_list2:
        sum += i
        my_list1.append(i)
    print(sum)


to_be_profiled()

import sys

@profile

def to_be_profiled():

my_list1 = [i**2 for i in range(50000)]

my_list2 = (i**2 for i in range(100000, 150000))

sum = 0

print("my_list1 = {} bytes".format(sys.getsizeof(my_list1)))

print("my_list2 = {} bytes".format(sys.getsizeof(my_list2)))

for i in my_list2:

sum += i

my_list1.append(i)

print(sum)

to_be_profiled()

my_list1 = 406496 bytes
my_list2 = 88 bytes
791660416675000
Wrote profile results to line.py.lprof
Timer unit: 1e-06 s

Total time: 0.17311 s
File: line.py
Function: to_be_profiled at line 3

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     3                                           @profile
     4                                           def to_be_profiled():
     5
     6         1        17575  17575.0     10.2      my_list1 = [i**2 for i in range(50000)]
     7
     8         1            7      7.0      0.0      my_list2 = (i**2 for i in range(100000, 150000))
     9         1            1      1.0      0.0      sum = 0
    10         1           43     43.0      0.0      print("my_list1 = {} bytes".format(sys.getsizeof(my_li
st1)))
    11         1           24     24.0      0.0      print("my_list2 = {} bytes".format(sys.getsizeof(my_li
st2)))
    12
    13     50001        68438      1.4     39.5      for i in my_list2:
    14     50000        42867      0.9     24.8          sum += i
    15     50000        44122      0.9     25.5          my_list1.append(i)
    16         1           33     33.0      0.0      print(sum)

my_list1 = 406496 bytes

my_list2 = 88 bytes

791660416675000

Wrote profile results to line.py.lprof

Timer unit: 1e-06 s

Total time: 0.17311 s

File: line.py

Function: to_be_profiled at line 3

Line # Hits Time Per Hit % Time Line Contents

==============================================================

3 @profile

4 def to_be_profiled():

6 1 17575 17575.0 10.2 my_list1 = [i**2 for i in range(50000)]

8 1 7 7.0 0.0 my_list2 = (i**2 for i in range(100000, 150000))

9 1 1 1.0 0.0 sum = 0

10 1 43 43.0 0.0 print("my_list1 = {} bytes".format(sys.getsizeof(my_li

st1)))

11 1 24 24.0 0.0 print("my_list2 = {} bytes".format(sys.getsizeof(my_li

st2)))

13 50001 68438 1.4 39.5 for i in my_list2:

14 50000 42867 0.9 24.8 sum += i

15 50000 44122 0.9 25.5 my_list1.append(i)

16 1 33 33.0 0.0 print(sum)

Burada performans ölçüm modüllerinin kullanımını ele aldık.