分析 Python cProfile 与 unix 时间

Posted 2023-03-11

【中文标题】分析 Python cProfile 与 unix 时间

【英文标题】：Profile Python cProfile vs unix time

【发布时间】：2011-09-23 01:17:32

【问题描述】：

我正在分析一个 python 代码；为什么它会在用户空间中花费更多时间？

 

     user@terminal$ time python main.py 

     1964 function calls in 0.003 CPU seconds


Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.003    0.003 :1()
        1    0.000    0.000    0.000    0.000 ConfigParser.py:218(init)
        1    0.000    0.000    0.001    0.001 ConfigParser.py:266(read)
       30    0.000    0.000    0.000    0.000 ConfigParser.py:354(optionxform)
        1    0.000    0.000    0.000    0.000 ConfigParser.py:434(_read)
       15    0.000    0.000    0.000    0.000 ConfigParser.py:515(get)
       15    0.000    0.000    0.000    0.000 ConfigParser.py:611(_interpolate)
       15    0.000    0.000    0.000    0.000 ConfigParser.py:619(_interpolate_some)
        1    0.000    0.000    0.000    0.000 config.py:32(read_config_data)
        1    0.000    0.000    0.001    0.001 config.py:9(init)
        6    0.000    0.000    0.000    0.000 entity.py:108(add_to_filter)
        1    0.000    0.000    0.002    0.002 entity.py:24(init)
        1    0.001    0.001    0.002    0.002 entity.py:39(create_inverted_index)
      493    0.000    0.000    0.001    0.000 entity.py:80(beautify)
        1    0.000    0.000    0.000    0.000 entity.py:84(create_bucket_lookup)
        1    0.000    0.000    0.000    0.000 main.py:15()
        2    0.000    0.000    0.000    0.000 main.py:18()
        1    0.000    0.000    0.003    0.003 main.py:23(main)
        1    0.000    0.000    0.000    0.000 main.py:9(get_bag_of_words)
       19    0.000    0.000    0.000    0.000 built-in method group
       34    0.000    0.000    0.000    0.000 built-in method match
        1    0.000    0.000    0.000    0.000 isinstance
        2    0.000    0.000    0.000    0.000 len
       28    0.000    0.000    0.000    0.000 method 'append' of 'list' objects
        1    0.000    0.000    0.000    0.000 method 'close' of 'file' objects
       15    0.000    0.000    0.000    0.000 method 'copy' of 'dict' objects
        1    0.000    0.000    0.000    0.000 method 'disable' of '_lsprof.Profiler' objects
       15    0.000    0.000    0.000    0.000 method 'find' of 'str' objects
       19    0.000    0.000    0.000    0.000 method 'isspace' of 'str' objects
       24    0.000    0.000    0.000    0.000 method 'join' of 'str' objects
       49    0.000    0.000    0.000    0.000 method 'lower' of 'str' objects
       20    0.000    0.000    0.000    0.000 method 'readline' of 'file' objects
        6    0.000    0.000    0.000    0.000 method 'replace' of 'str' objects
       24    0.000    0.000    0.000    0.000 method 'rstrip' of 'str' objects
       47    0.000    0.000    0.000    0.000 method 'split' of 'str' objects
        9    0.000    0.000    0.000    0.000 method 'startswith' of 'str' objects
     1030    0.000    0.000    0.000    0.000 method 'strip' of 'str' objects
       15    0.000    0.000    0.000    0.000 method 'update' of 'dict' objects
        2    0.000    0.000    0.000    0.000 method 'write' of 'file' objects
       10    0.000    0.000    0.000    0.000 open
        2    0.000    0.000    0.000    0.000 range
        3    0.000    0.000    0.000    0.000 reduce

Done 

real    0m0.063s
user    0m0.050s
sys 0m0.010s

虽然 cProfile 说它只用了 0.003 秒，但为什么 unix (sys) 时间说它在 0.01 秒内运行？

【参考方案1】：

time(1)是衡量整个进程的执行时间，而profiler不包括Python解释器启动时间、字节码编译时间等。

【讨论】：

发生这种情况的任何原因？ twitpic.com/5ha6qe 从某种意义上说，为什么 Python 在用户空间中花费更多时间？