This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: cProfile behaviour issue with decorator and math.factorial() lib.
Type: behavior Stage: resolved
Components: Library (Lib) Versions: Python 3.8
process
Status: closed Resolution: later
Dependencies: Superseder:
Assigned To: Nosy List: AVicennA, mark.dickinson, pablogsal, rhettinger
Priority: normal Keywords:

Created on 2019-12-07 13:24 by AVicennA, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Messages (7)
msg358010 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-12-08 15:54
Please, could you write a description to this issue here instead of the attached file?
msg358035 - (view) Author: AVicennA (AVicennA) * Date: 2019-12-08 21:42
Hello, I use decorators in my Python project. I tested project with cProfile(profiling). Then,
I decide did test with some decorator code fragments. Some results were surprising:

import functools
import cProfile

def decor(func):
    @functools.wraps(func)
    def wraps(*args, **kwargs):
        return func(*args, **kwargs)
    return wraps

@decor
def count(g_val):
    if g_val < 1:
        print("End")
    else:
        count(g_val - 1)
 
cProfile.run('count(102)')

OS names: Windows, Linux  -  x64
Python versions: 3.6.8, 3.4.3  -  x64

# cProfile using into the .py file
python dec_profile.py

End
         210 function calls (6 primitive calls) in 0.000 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <string>:1(<module>)
    103/1    0.000    0.000    0.000    0.000 timeer.py:10(count)
    103/1    0.000    0.000    0.000    0.000 timeer.py:5(wraps)
        1    0.000    0.000    0.000    0.000 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.print}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

# Instead of 102 used ---> 82, 22, 33, 72 and etc. also gave me strange results like in 102. 
This behaviour can be changing sometimes, but usually give an incorrect results.

import functools
import cProfile

def decor(func):
    @functools.wraps(func)
    def wraps(*args, **kwargs):
        return func(*args, **kwargs)
    return wraps

@decor
def count(g_val):
    if g_val < 1:
        print("End")
    else:
        count(g_val - 1)
 
count(102)

# cProfile using via command line
python -m cProfile dec_profile.py

End
         539 function calls (334 primitive calls) in 0.002 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:103(release)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:143(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:147(__enter__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:151(__exit__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:157(_get_module_lock)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:176(cb)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:211(_call_with_frames_removed)
       26    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:222(_verbose_message)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:307(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:311(__enter__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:318(__exit__)
        4    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:321(<genexpr>)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:35(_new_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:369(__init__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:403(cached)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:416(parent)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:424(has_location)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:504(_init_module_attrs)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:564(module_from_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:58(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:651(_load_unlocked)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:707(find_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:78(acquire)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:780(find_spec)
        3    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:843(__enter__)
        3    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:847(__exit__)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap>:870(_find_spec)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap>:936(_find_and_load_unlocked)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap>:966(_find_and_load)
        6    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1080(_path_importer_cache)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap_external>:1117(_get_spec)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap_external>:1149(find_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1228(_get_spec)
        5    0.000    0.000    0.001    0.000 <frozen importlib._bootstrap_external>:1233(find_spec)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:263(cache_from_source)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:361(_get_cached)
        5    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:37(_relax_case)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:393(_check_name_wrapper)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:430(_validate_bytecode_header)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:485(_compile_bytecode)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:52(_r_long)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:524(spec_from_file_location)
       25    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:57(_path_join)
       25    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:59(<listcomp>)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:63(_path_split)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:669(create_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:672(exec_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:743(get_code)
        7    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:75(_path_stat)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:800(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:825(get_filename)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:830(get_data)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:840(path_stats)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:85(_path_is_mode_type)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:94(_path_isfile)
        1    0.000    0.000    0.000    0.000 cProfile.py:27(Profile)
        1    0.000    0.000    0.000    0.000 cProfile.py:5(<module>)
        1    0.000    0.000    0.000    0.000 functools.py:44(update_wrapper)
        1    0.000    0.000    0.000    0.000 functools.py:74(wraps)
        1    0.000    0.000    0.002    0.002 timeer.py:1(<module>)
    103/1    0.000    0.000    0.000    0.000 timeer.py:10(count)
        1    0.000    0.000    0.000    0.000 timeer.py:4(decor)
    103/1    0.000    0.000    0.000    0.000 timeer.py:5(wraps)
        1    0.000    0.000    0.000    0.000 {built-in method _imp._fix_co_filename}
        5    0.000    0.000    0.000    0.000 {built-in method _imp.acquire_lock}
        1    0.000    0.000    0.000    0.000 {built-in method _imp.is_builtin}
        1    0.000    0.000    0.000    0.000 {built-in method _imp.is_frozen}
        5    0.000    0.000    0.000    0.000 {built-in method _imp.release_lock}
        2    0.000    0.000    0.000    0.000 {built-in method _thread.allocate_lock}
        2    0.000    0.000    0.000    0.000 {built-in method _thread.get_ident}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.__build_class__}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.any}
      2/1    0.000    0.000    0.002    0.002 {built-in method builtins.exec}
       13    0.000    0.000    0.000    0.000 {built-in method builtins.getattr}
        7    0.000    0.000    0.000    0.000 {built-in method builtins.hasattr}
        7    0.000    0.000    0.000    0.000 {built-in method builtins.isinstance}
        4    0.000    0.000    0.000    0.000 {built-in method builtins.len}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.print}
        5    0.000    0.000    0.000    0.000 {built-in method builtins.setattr}
        2    0.000    0.000    0.000    0.000 {built-in method from_bytes}
        1    0.000    0.000    0.000    0.000 {built-in method marshal.loads}
        3    0.000    0.000    0.000    0.000 {built-in method nt.fspath}
        2    0.000    0.000    0.000    0.000 {built-in method nt.getcwd}
        7    0.000    0.000    0.000    0.000 {built-in method nt.stat}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    0.000    0.000 {method 'endswith' of 'str' objects}
        2    0.000    0.000    0.000    0.000 {method 'get' of 'dict' objects}
       27    0.000    0.000    0.000    0.000 {method 'join' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {method 'read' of '_io.FileIO' objects}
        9    0.000    0.000    0.000    0.000 {method 'rpartition' of 'str' objects}
        2    0.000    0.000    0.000    0.000 {method 'rsplit' of 'str' objects}
       52    0.000    0.000    0.000    0.000 {method 'rstrip' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {method 'update' of 'dict' objects}


Here also interesting results in computation with some factorial estimations:

import math
import cProfile

def fact(n):
    return sum(1 / math.factorial(n) for n in range(18))

print(cProfile.run('fact(200)'))

# cProfile into the .py file
python fact.py

42 function calls in 0.000 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <string>:1(<module>)
        1    0.000    0.000    0.000    0.000 timeer.py:5(fact)
       19    0.000    0.000    0.000    0.000 timeer.py:6(<genexpr>)
        1    0.000    0.000    0.000    0.000 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.sum}
       18    0.000    0.000    0.000    0.000 {built-in method math.factorial}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

import math
import cProfile

def fact(n):
    print(sum(1 / math.factorial(n) for n in range(18)))

fact(200)

# cProfile using via command line
python -m cProfile fact.py

2.7182818284590455
         417 function calls (416 primitive calls) in 0.001 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:103(release)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:143(__init__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:147(__enter__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:151(__exit__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:157(_get_module_lock)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:176(cb)
        3    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:211(_call_with_frames_removed)
       27    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:222(_verbose_message)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:232(_requires_builtin_wrapper)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:307(__init__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:311(__enter__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:318(__exit__)
        8    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:321(<genexpr>)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:35(_new_module)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:369(__init__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:403(cached)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:416(parent)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:424(has_location)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:433(spec_from_loader)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:504(_init_module_attrs)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:564(module_from_spec)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:58(__init__)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:651(_load_unlocked)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:707(find_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:728(create_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:736(exec_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:753(is_package)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:78(acquire)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:780(find_spec)
        4    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:843(__enter__)
        4    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:847(__exit__)
        2    0.000    0.000    0.001    0.000 <frozen importlib._bootstrap>:870(_find_spec)
        2    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap>:936(_find_and_load_unlocked)
        2    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap>:966(_find_and_load)
        6    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1080(_path_importer_cache)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap_external>:1117(_get_spec)
        1    0.000    0.000    0.001    0.001 <frozen importlib._bootstrap_external>:1149(find_spec)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:1228(_get_spec)
        5    0.000    0.000    0.001    0.000 <frozen importlib._bootstrap_external>:1233(find_spec)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:263(cache_from_source)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:361(_get_cached)
        5    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:37(_relax_case)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:393(_check_name_wrapper)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:430(_validate_bytecode_header)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:485(_compile_bytecode)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:52(_r_long)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:524(spec_from_file_location)
       25    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:57(_path_join)
       25    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:59(<listcomp>)
        2    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:63(_path_split)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:669(create_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:672(exec_module)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:743(get_code)
        7    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:75(_path_stat)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:800(__init__)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:825(get_filename)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:830(get_data)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:840(path_stats)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:85(_path_is_mode_type)
        1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap_external>:94(_path_isfile)
        1    0.000    0.000    0.000    0.000 cProfile.py:27(Profile)
        1    0.000    0.000    0.000    0.000 cProfile.py:5(<module>)
        1    0.000    0.000    0.001    0.001 timeer.py:1(<module>)
        1    0.000    0.000    0.000    0.000 timeer.py:4(fact)
       19    0.000    0.000    0.000    0.000 timeer.py:5(<genexpr>)
        1    0.000    0.000    0.000    0.000 {built-in method _imp._fix_co_filename}
        8    0.000    0.000    0.000    0.000 {built-in method _imp.acquire_lock}
        1    0.000    0.000    0.000    0.000 {built-in method _imp.create_builtin}
        1    0.000    0.000    0.000    0.000 {built-in method _imp.exec_builtin}
        2    0.000    0.000    0.000    0.000 {built-in method _imp.is_builtin}
        1    0.000    0.000    0.000    0.000 {built-in method _imp.is_frozen}
        8    0.000    0.000    0.000    0.000 {built-in method _imp.release_lock}
        4    0.000    0.000    0.000    0.000 {built-in method _thread.allocate_lock}
        4    0.000    0.000    0.000    0.000 {built-in method _thread.get_ident}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.__build_class__}
        2    0.000    0.000    0.000    0.000 {built-in method builtins.any}
      2/1    0.000    0.000    0.001    0.001 {built-in method builtins.exec}
       10    0.000    0.000    0.000    0.000 {built-in method builtins.getattr}
       11    0.000    0.000    0.000    0.000 {built-in method builtins.hasattr}
        7    0.000    0.000    0.000    0.000 {built-in method builtins.isinstance}
        4    0.000    0.000    0.000    0.000 {built-in method builtins.len}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.print}
        1    0.000    0.000    0.000    0.000 {built-in method builtins.sum}
        2    0.000    0.000    0.000    0.000 {built-in method from_bytes}
        1    0.000    0.000    0.000    0.000 {built-in method marshal.loads}
       18    0.000    0.000    0.000    0.000 {built-in method math.factorial}
        3    0.000    0.000    0.000    0.000 {built-in method nt.fspath}
        2    0.000    0.000    0.000    0.000 {built-in method nt.getcwd}
        7    0.000    0.000    0.000    0.000 {built-in method nt.stat}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    0.000    0.000 {method 'endswith' of 'str' objects}
        4    0.000    0.000    0.000    0.000 {method 'get' of 'dict' objects}
       27    0.000    0.000    0.000    0.000 {method 'join' of 'str' objects}
        1    0.000    0.000    0.000    0.000 {method 'read' of '_io.FileIO' objects}
       11    0.000    0.000    0.000    0.000 {method 'rpartition' of 'str' objects}
        2    0.000    0.000    0.000    0.000 {method 'rsplit' of 'str' objects}
       52    0.000    0.000    0.000    0.000 {method 'rstrip' of 'str' objects}

In cProfile documentation isn't talking about command line behaviour difference.
msg358042 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2019-12-08 23:40
@AVicennA Can you clarify exactly which part of the output you find surprising, and why, and what result you expected instead? It's a little hard to tell which details in your message we're supposed to be looking at.
msg358056 - (view) Author: AVicennA (AVicennA) * Date: 2019-12-09 06:47
In short, here are different behaviours in increasing steps of values, which are (based on my researching) giving incorrect results in relation to each other.

Given example:

import functools
import cProfile

def decor(func):
    @functools.wraps(func)
    def wraps(*args, **kwargs):
        return func(*args, **kwargs)
    return wraps

@decor
def count(g_val):
    if g_val < 1:
        print("End")
    else:
        count(g_val - 1)
		
cProfile.run('count(VALUE)')
		

Below I wrote results by given values...

1) VALUE = 50

End                                                                                                                                                                                
         106 function calls (6 primitive calls) in 0.000 seconds                                                                                                                   
                                                                                                                                                                                   
   Ordered by: standard name                                                                                                                                                       
                                                                                                                                                                                   
   ncalls  tottime  percall  cumtime  percall filename:lineno(function)                                                                                                            
        1    0.000    0.000    0.000    0.000 <string>:1(<module>)                                                                                                                 
     51/1    0.000    0.000    0.000    0.000 main.py:10(count)                                                                                                                    
     51/1    0.000    0.000    0.000    0.000 main.py:5(wraps)                                                                                                                     
        1    0.000    0.000    0.000    0.000 {built-in method exec}                                                                                                               
        1    0.000    0.000    0.000    0.000 {built-in method print}                                                                                                              
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

		
2) VALUE = 45	
End                                                                                                                                                                                
         96 function calls (6 primitive calls) in 0.062 seconds                                                                                                                    
                                                                                                                                                                                   
   Ordered by: standard name                                                                                                                                                       
                                                                                                                                                                                   
   ncalls  tottime  percall  cumtime  percall filename:lineno(function)                                                                                                            
        1    0.000    0.000    0.062    0.062 <string>:1(<module>)                                                                                                                 
     46/1    0.000    0.000    0.061    0.061 main.py:10(count)                                                                                                                    
     46/1    0.000    0.000    0.062    0.062 main.py:5(wraps)                                                                                                                     
        1    0.000    0.000    0.062    0.062 {built-in method exec}                                                                                                               
        1    0.061    0.061    0.061    0.061 {built-in method print}                                                                                                              
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
	
	
3) VALUE = 26		
End                                                                                                                                                                                
         58 function calls (6 primitive calls) in 0.003 seconds                                                                                                                    
                                                                                                                                                                                   
   Ordered by: standard name                                                                                                                                                       
                                                                                                                                                                                   
   ncalls  tottime  percall  cumtime  percall filename:lineno(function)                                                                                                            
        1    0.000    0.000    0.002    0.002 <string>:1(<module>)                                                                                                                 
     27/1    0.000    0.000    0.002    0.002 main.py:10(count)                                                                                                                    
     27/1    0.000    0.000    0.002    0.002 main.py:5(wraps)                                                                                                                     
        1    0.000    0.000    0.003    0.003 {built-in method exec}                                                                                                               
        1    0.002    0.002    0.002    0.002 {built-in method print}                                                                                                              
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
		
As you see above samples are giving surprise results.. 50 - gave 0 sec., but how 26 - gave 0.003 sec or 45 - gave 0.062 sec. Instead of these results I expected increased seconds by linearly.
msg358360 - (view) Author: AVicennA (AVicennA) * Date: 2019-12-13 21:46
In official documentation: https://docs.python.org/3/library/profile.html was not noted about the difference behaviour of cProfile in command line and into the file.
msg358368 - (view) Author: Raymond Hettinger (rhettinger) * (Python committer) Date: 2019-12-14 00:45
This doesn't seem like an appropriate use of the bug tracker.

Investigating and explaining cProfile results seems better suited for StackOverflow or some other forum.  Then if an actual known bug or potential optimization arises, the bug tracker can to used to follow-up on a specific request.  

Being "surprised" by timing/profling results usually isn't a bug and can sometimes be resolved by studying the source to how one's simplified mental model differs from the realities faced by a real-world implementation.

I recommend closing this but allowing it to be reopened if specific improvement can be proposed.
msg358369 - (view) Author: AVicennA (AVicennA) * Date: 2019-12-14 00:57
@rhettinger, I did not write nowhere in my post that it's a pure bug. I use "behaviour" instead of it. And it getting me incorrect results everytime, that is why I should wrote it in here for resolving this problem. This is not about getting error message, that write to Stackoverflow. I think you were not checking this never.
History
Date User Action Args
2022-04-11 14:59:24adminsetgithub: 83174
2019-12-16 19:15:12AVicennAsetresolution: not a bug -> later
2019-12-16 18:36:37AVicennAsetfiles: - cProfiling.txt
2019-12-16 12:39:53mark.dickinsonsetstatus: open -> closed
resolution: not a bug
stage: resolved
2019-12-14 00:57:09AVicennAsetmessages: + msg358369
2019-12-14 00:45:47rhettingersetnosy: + rhettinger
messages: + msg358368
2019-12-13 21:46:59AVicennAsetmessages: + msg358360
2019-12-09 06:47:28AVicennAsetmessages: + msg358056
2019-12-08 23:40:05mark.dickinsonsetnosy: + mark.dickinson
messages: + msg358042
2019-12-08 21:42:42AVicennAsetmessages: + msg358035
2019-12-08 15:54:28pablogsalsetnosy: + pablogsal
messages: + msg358010
2019-12-07 13:24:12AVicennAcreate