Python多处理脚本中的打印时间返回负数已用时间答案

【问题标题】：Printing time in Python multiprocessing script return negative time elapsedPython多处理脚本中的打印时间返回负数已用时间
【发布时间】：2014-04-27 12:07:30
【问题描述】：

使用 Python 2.7.6

在 Ubuntu 14 上运行它

我简化了脚本来显示我的问题：

import time
import multiprocessing

data = range(1, 3)
start_time = time.clock()


def lol():
    for i in data:
        print time.clock() - start_time, "lol seconds"


def worker(n):
    print time.clock() - start_time, "multiprocesor seconds"


def mp_handler():
    p = multiprocessing.Pool(1)
    p.map(worker, data)

if __name__ == '__main__':
    lol()
    mp_handler()

还有输出：

8e-06 lol seconds
6.9e-05 lol seconds
-0.030019 multiprocesor seconds
-0.029907 multiprocesor seconds

    Process finished with exit code 0

使用time.time() 会给出非负值（此处标记为Timer shows negative time elapsed）但我很好奇 python multiprocessing 中的 time.clock() 和从 CPU 读取时间有什么问题。

【问题讨论】：

标签： python python-2.7 time multiprocessing

【解决方案1】：

multiprocessing spawns new 进程和linux上的time.clock()与C的clock()含义相同：

返回的值是到目前为止使用的CPU时间作为clock_t；

所以clock 返回的值会在进程启动时从0 重新启动。但是，您的代码使用父进程的进程start_time 来确定在子进程中花费的时间，如果子进程 CPU 时间重置，这显然是不正确的。

clock() 函数只有在处理一个进程时才有意义，因为它的返回值是那个进程花费的CPU时间。不考虑子进程。

另一方面，time() 函数使用系统范围的时钟，因此甚至可以在不同的进程之间使用（虽然它不是单调的，所以如果有人可能会返回错误的结果在事件期间更改系统时间）。

分叉一个正在运行的 python 实例可能比从头开始一个新实例更快，因此start_time 几乎总是大于time.clock() 返回的值。考虑到父进程还必须读取磁盘上的文件、执行可能需要读取其他 .py 文件、搜索目录等的导入。分叉的子进程不必做所有这些。

显示time.clock()的返回值重置为0的示例代码：

from __future__ import print_function

import time
import multiprocessing

data = range(1, 3)
start_time = time.clock()


def lol():
    for i in data:
        t = time.clock()
        print('t: ', t, end='\t')
        print(t - start_time, "lol seconds")


def worker(n):
    t = time.clock()
    print('t: ', t, end='\t')
    print(t - start_time, "multiprocesor seconds")


def mp_handler():
    p = multiprocessing.Pool(1)
    p.map(worker, data)

if __name__ == '__main__':
    print('start_time', start_time)
    lol()
    mp_handler()

结果：

$python ./testing.py 
start_time 0.020721
t:  0.020779    5.8e-05 lol seconds
t:  0.020804    8.3e-05 lol seconds
t:  0.001036    -0.019685 multiprocesor seconds
t:  0.001166    -0.019555 multiprocesor seconds

注意t 在lol 情况下是单调的，而在其他情况下又回到0.001。

【讨论】：

【解决方案2】：

要在上面 Bakuriu 的出色答案中添加一个简洁的 Python 3 示例，您可以使用以下方法来获取独立于子进程的全局计时器：

import multiprocessing as mp
import time

# create iterable
iterable = range(4)

# adds three to the given element
def add_3(num):
    a = num + 3
    return a

# multiprocessing attempt
def main():
    pool = mp.Pool(2)
    results = pool.map(add_3, iterable)    
    return results

if __name__ == "__main__":  #Required not to spawn deviant children    
    start=time.time()

    results = main()
    print(list(results))

    elapsed = (time.time() - start)  
    print("\n","time elapsed is :", elapsed)

请注意，如果我们使用 time.process_time() 而不是 time.time()，我们将得到不希望的结果。

【讨论】：