Какова взаимосвязь между временем процессора, измеренным профилировщиком Python, и реальным временем пользователя и системного времени? - PullRequest
Новая
       20

Какова взаимосвязь между временем процессора, измеренным профилировщиком Python, и реальным временем пользователя и системного времени?

12 голосов
/ 02 марта 2012

Использование встроенного в Python профилировщика с запуском скрипта в одном процессоре (без многопоточности) 

time python -m cProfile myscript.py

время процессора, сообщаемое профилировщиком, составляет 345,710 секунд процессора 

24184348 function calls (24183732 primitive calls) in 345.710 CPU seconds

и real , user и sys время: 

real    5m45.926s
user    1m59.340s
sys     0m39.452s

Как вы можете видеть, процессорное время почти в реальном времени (345,710 = 5м45,710 с).

Таким образом, с учетом этого результата можно ли предположить, что время ЦП, сообщаемое профилировщиком, включает в себя временные интервалы, используемые другими процессами, и время, которое процесс проводит заблокированным? то есть, что процессорное время профилировщика - это не время процесса (пользователь + sys), а время настенных часов, как это объясняется в Что означают 'real', 'user' и 'sys' в выводе времени (1)?

Заранее большое спасибо

Ответы [ 3 ]

13 голосов
/ 02 марта 2012

Это отвечает прекрасные детали о значении реальных, пользовательских и системных таймингов.Процитируем:

  • «Реальное» - это время настенных часов - время от начала до конца разговора.Это все прошедшее время, включая временные интервалы, используемые другими процессами, и время, которое процесс блокирует (например, если он ожидает завершения ввода-вывода).

  • «Пользователь» - этоколичество процессорного времени, потраченного в коде пользовательского режима (вне ядра) внутри процесса.Это только фактическое время процессора, используемое при выполнении процесса.Другие процессы и время, которое процесс заблокировал, не учитываются в этом значении.

  • 'Sys' - это количество процессорного времени, проведенного в ядре внутри процесса.Это означает выполнение процессорного времени, затраченного на системные вызовы в ядре, в отличие от библиотечного кода, который все еще выполняется в пользовательском пространстве.Как и «пользователь», это только процессорное время, используемое процессом.

Из приведенного выше объяснения видно, что время Пользователь + Sys должно быть равно секундам процессора.Вместо этого ближе к «реальному» времени.Странный!

Этому есть справедливое объяснение.Время пользователя не включает в себя секунды ЦП, затраченные на операции ввода-вывода в процессе.Он просто измеряет время процессора, потраченное на код пользовательского режима в памяти .Основное правило:

реальное время = пользователь + sys + время ввода-вывода + время запуска интерпретатора + время компиляции байт-кода

Чтобы проверить это, я сделал urllib2.urlopen(urllib2.Request(url)) вызов с интенсивным вводом / выводом.Вот результаты: 

         100792 function calls (98867 primitive calls) in 2.076 CPU seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      512    0.719    0.001    0.719    0.001 {method 'recv' of '_socket.socket' objects}
        1    0.464    0.464    0.473    0.473 {_socket.getaddrinfo}
        1    0.352    0.352    0.352    0.352 <string>:1(connect)
        1    0.248    0.248    0.348    0.348 common_functions.py:1(<module>)
        1    0.022    0.022    0.075    0.075 __init__.py:2(<module>)
        1    0.017    0.017    0.030    0.030 urllib.py:1442(getproxies_macosx_sysconf)
   330/67    0.012    0.000    0.031    0.000 sre_parse.py:385(_parse)


real    0m2.255s
user    0m0.352s
sys 0m0.093s

Здесь 2,076- (0,352 + 0,093), т. Е. 1,631 сек. ЦП было использовано в операциях ввода / вывода (в основном _socket.socket и _socket.getaddrinfo).Остальное время, 2.255-2.076, было потрачено на холодный запуск кода.

Надеюсь, что это было полезно.

Обновление : в многоядерных системах, где несколькоПроцессоры работают параллельно, корпус немного другой.Общее количество секунд процессора, сообщаемое cProfile, представляет собой сумму времени, потраченного всеми процессорами индивидуально.Например: в двухъядерной системе, если один процессор работает в течение 10 секунд.Параллельно другой процессор работает в течение 15 секунд.Общее количество сообщенных секунд ЦП составит 25 секунд.Хотя в реальном времени может пройти всего 15 секунд.Следовательно, процессорное время может быть больше, чем в реальном времени в многоядерных системах. Поскольку процессоры работают параллельно

7 голосов
/ 28 июня 2013

Я был озадачен той же проблемой.

Ответ в том, что cProfile использует время настенных часов. И его вывод был исторически неправильным, но теперь исправлен («CPU» в «CPU секундах» был удален). Я точно не знаю, когда, но в Python 2.6.6 в Debian 6.0 есть ошибка, в то время как Python 2.7.3 в Debian 7.0 в порядке.

Это озадачивает, потому что большинство профилировщиков учитывают время, потраченное на ЦП, а не время настенных часов. Но это «дешевый» профилировщик.

Документ http://docs.python.org/2/library/profile.html#limitations объясняет - неясно - что время основано на тиканье на стене, а не на методах getrusage () или ptrace.

Если вы проверите код (http://hg.python.org/cpython/file/44f455e6163d/Modules/_lsprof.c), вы можете убедиться, что он основан на QueryPerformanceFrequency / gettimeofday.

Jerrymouse прав в том, что время и время cProfile не могут совпадать, потому что cProfile запускается только после компиляции кода. Но, кроме того, его уравнение в реальном времени является поддельным.

Разница между wallclock и user + sys может заключаться во многих различных факторах, таких как ввод-вывод от имени вашего процесса или от имени любых других процессов, включая само ядро ​​(подкачка, ведение журнала и т. Д.) Или время процессора потраченные на другие процессы или ожидающие чего-либо от имени вашего процесса, который не может быть учтен, поскольку это удаленный ресурс (сетевой или косвенный через NFS или iSCSI) и т. д. Вы называете его.

6 голосов
/ 02 августа 2013

Профилировщик Python по умолчанию измеряет время на стене, но его можно настроить для измерения времени процессора, используя функцию таймера. Следующее работает в Linux, но не в Windows (поскольку time.clock измеряет время ожидания в Windows): 

import cProfile
import time


def idleWait():
    time.sleep(10)

def busyWait():
    t = time.time() + 10
    while time.time() < t: pass

def target():
    idleWait()
    busyWait()


print "Wall time:"
p = cProfile.Profile()
p.runcall(target)
p.print_stats()

print "CPU time:"
p = cProfile.Profile(time.clock)
p.runcall(target)
p.print_stats()

Первый запуск профиля покажет 20 секунд, из которых около половины потрачено на time.sleep. Вторая показывает, что прошло 10 секунд, и ни одна из них не потрачена на time.sleep.

...