Cython 代码分析答案

【问题标题】：Profiling of Cython codeCython 代码分析
【发布时间】：2015-11-09 11:18:26
【问题描述】：

我有以下Cython 代码：

# cython: profile=True
import cProfile
from cython import parallel
from libc.stdio cimport FILE, fopen, fclose, fwrite, getline, printf
from libc.string cimport strlen
from libcpp.string cimport string
cdef extern from "stdio.h" nogil:
   int mkstemp(char*);

cdef run_io(string obj):
    cdef int i, dump
    cdef size_t len_ = 0
    cdef char* fname = "/tmp/tmpc_XXXXXX"
    cdef char* nullchar = NULL
    cdef char* line = NULL
    cdef string content = b""
    cdef FILE* cfile
    for i in range(10000):
        dump = mkstemp(fname)
        cfile = fopen(fname, "wb")
        fwrite(obj.data(), 1, obj.size(), cfile)
        fclose(cfile)
        cfile = fopen(fname, "rb")
        while True:
            if getline(&line, &len_, cfile) == -1:
                break
            else:
                content.append(line)
        fclose(cfile)

def run_test():
    cdef string obj = b"abc\ndef"
    cProfile.runctx("run_io(obj)", globals(), locals())

当我尝试从python3 控制台运行它时，我收到错误：

NameError: name 'run_io' is not defined

如果我将run_io 函数cdef 的定义更改为def，它会起作用：

         7 function calls in 2.400 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    2.400    2.400 <string>:1(<module>)
        2    0.000    0.000    0.000    0.000 stringsource:13(__pyx_convert_string_from_py_std__in_string)
        1    2.400    2.400    2.400    2.400 testc2.pyx:10(run_io)
        1    0.000    0.000    2.400    2.400 {built-in method exec}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    2.400    2.400 {test.run_io}

但是，这不是很丰富，因为我只看到整个函数的总运行时间（我希望看到生成文件名、读取、写入等的部分运行时间）。

因此，我有两个问题：

是否可以分析Cython 函数（使用cdef 定义）？如果是，怎么做？
如何使分析提供更多信息（即测量每个调用函数所花费的时间）？

【问题讨论】：

标签： python profiling cython

【解决方案1】：

python 和 cpython 分析是确定性的，这意味着它们通过在函数的进入和退出时捕捉墙时间来工作，但只有分析器被告知要分析的函数。它们无法为您提供逐行的时间信息，除非它们还捕获每行代码之前和/或之后的时间。

如果您不介意放弃测量精度（这并不是人们所说的全部），获取逐行信息的一种方法是获取少量堆栈样本。每行代码都有包含时间 (cumtime) 作为总时间的一部分，而这正是它在堆栈上的时间的一部分。因此，当您获取堆栈样本时，该分数就是您将看到它的概率。如果您查看 10 或 20 个样本，您会很清楚哪些代码行需要花费大量时间。 Here's an example.

:) 我有时听到的反对意见是“这不会完全减慢程序并使结果无效吗？”好的，考虑一下。有一行代码，它需要一小部分时间，比如 36.5%，所以它在堆栈上的那部分时间。现在您启动程序，9 秒后您中断它查看堆栈。该行在堆栈上的可能性为 36.5%。现在，门铃响了，你直到一周后才回来看它。长达一周的延迟是否会改变该行在堆栈样本上的概率？当然不是。电脑很有耐心。无论您查看多长时间，该堆栈示例都不会更改。

【讨论】：