Описание
В моем коде для создания N случайных строк длины k выражение генератора для создания случайной строки k -символа вызывается либо N+1, либо (N+1)*k ( он же N*k+N) раз. Похоже, это происходит с точно таким же кодом , и я могу переключаться туда и обратно, казалось бы, недетерминированно, переопределив вспомогательную функцию chrs(). Я подозреваю профилировщик, но понятия не имею о механизме.
Сведения о системе, если они имеют значение: CPython, Python 2.7.17 и Python 3.6.9 на Ubuntu 18.04 на HP Envy 15k (i7-4720)
Воспроизведение проблемы
Неправильный MCVE, поскольку я не смог детерминированно воспроизвести проблему; вместо этого, мы надеемся, что это приведет к одному из двух выходных данных профилировщика ниже. Если вы попытаетесь запустить это в REPL и повторно определить функцию chrs(), используя один и тот же код, вы сможете получить оба выхода профилировщика.
Я написал эту bits_strings() функцию при тестировании различных способы генерации N (num_strings) случайных строк длины k (len_string):
import cProfile
import random
import string
def chrs(bits, len_string):
return ''.join(chr((bits >> (8*x)) & 0xff) for x in range(len_string))
def bits_strings(num_strings, len_string):
return list(
chrs(random.getrandbits(len_string*8), len_string)
for x in range(num_strings)
)
cProfile.run('bits_strings(1000, 2000)')
Для тестирования я использовал cProfile.run().
Когда Я запустил код в первый раз, он показался довольно быстрым:
cProfile.run('bits_strings(1000, 2000)')
2005005 function calls in 0.368 seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 1.970 1.970 <stdin>:1(bits_strings)
1000 0.001 0.000 1.963 0.002 <stdin>:1(chrs)
1001 0.001 0.000 1.970 0.002 <stdin>:2(<genexpr>)
1 0.000 0.000 1.970 1.970 <string>:1(<module>)
2000000 0.173 0.000 0.173 0.000 {chr}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
1000 0.005 0.000 0.005 0.000 {method 'getrandbits' of '_random.Random' objects}
1000 0.178 0.000 1.953 0.002 {method 'join' of 'str' objects}
1001 0.009 0.000 0.009 0.000 {range}
, но позже:
cProfile.run('bits_strings(1000, 2000)')
4005004 function calls in 1.960 seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 1.961 1.961 <stdin>:1(bits_strings)
1000 0.001 0.000 1.954 0.002 <stdin>:1(chrs)
2001000 1.593 0.000 1.762 0.000 <stdin>:2(<genexpr>)
1 0.000 0.000 1.961 1.961 <string>:1(<module>)
2000000 0.170 0.000 0.170 0.000 {chr}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
1000 0.005 0.000 0.005 0.000 {method 'getrandbits' of '_random.Random' objects}
1000 0.182 0.000 1.944 0.002 {method 'join' of 'str' objects}
1001 0.009 0.000 0.009 0.000 {range}
Разница выглядит так, как будто это <genexpr>, который - из cumtime и местоположения в различных аналогичных тестах я предположил, что это тот, который находится в chrs(). (Мой инстинкт подсказывает, что (chr((bits >> (8*x)) & 0xff) for x in range(len_string)) должен вызываться N раз, а chr((bits >> (8*x)) & 0xff) должен вызываться N*k раз).
Итак, в чем разница между двумя bits_strings() функции? Пытаясь найти разницу в коде между двумя попытками, я ничего не нашел. Фактически, у меня был сеанс Python REPL, в котором я определил функции, дважды запустил профилировщик (второй раз, чтобы проверить, была ли это проблема кеширования), а затем повторно определил функции, используя стрелку вверх, чтобы получить мой ранее введенный код. Он показал такое же расхождение: https://pastebin.com/1u1j1ZUt
Теории и мысли
ИЗМЕНИТЬ : Я подозреваю, что cProfile сейчас.
Переключение между «быстрой» и «медленной» версиями путем переопределения chrs(), но cProfile.run() было профилировано cProfile.run(). В оба наблюдаемых времени и согласно отчетам внешнего cProfile.run(), похоже, что внутренний cProfile.run() (тот, который профилирует bits_strings()) иногда занижает, сколько времени занимает bits_strings(): https://pastebin.com/C4W4FEjJ
Я также использовал time.time() до / после cProfile.run('bits_strings(1000,1000)) звонков и заметил несоответствие между «быстрым» профилем cumtime и фактическим временем настенных часов, затраченным при запуске метод.
Механизм все еще неясен.
Кеширование : тот же код, резко различающаяся производительность между запусками может быть кешированием вещь. Однако быстрая версия была первым запуском, который я когда-либо выполнял с этим кодом (хотя я раньше запускал другой код в том же сеансе REPL). И я могу переключаться с медленного на быстрое или с быстрого на медленное, просто переопределив chrs() и bits_strings(), хотя, действительно ли я переключаюсь или нет, кажется случайным. Также стоит отметить, что я смог переключить (afaict) только путем переопределения функций, а не просто перезапустив их. Поэтому я не уверен, что что будет кэшироваться или как это изменит количество вызовов <genexpr> с коэффициентом k при переопределении функции.
причуда cProfile : я запустил тот же код без cProfile.run() и рассчитал его, дважды получив текущий time.time() внутри bits_strings; общее затраченное время было сравнимо с временем cProfile.run() для медленного случая. Так что cProfile.run(), по крайней мере, не замедляет работу. Есть вероятность, что быстрый результат испорчен cProfile.run(), , но, как ни странно, для больших значений N и k ((10000, 10000)) я заметил заметную разницу между первым запуском bits_strings() и медленный позже днем .
причуда интерпретатора : Я думал, что это могло происходить из-за того, что интерпретатор ошибочно оптимизирует выражения генератора внутри chrs() и bits_strings(), но это то, за что вы платите -вы пишете CPython интерпретатор, так что это кажется маловероятным.
Python 2,7 причуда : переопределение chrs() (с помощью стрелки вверх чтобы восстановить предыдущее определение) непоследовательно выполняет тот же трюк в python3: https://pastebin.com/Uw7PgF7i
Zal go, чтобы отомстить за это один раз я проанализировал HTML с регулярным выражением : не исключено
Мне очень хочется верить, что bits_strings() в разное время (разные определения одна и та же функция с одним и тем же кодом, а не разными запусками), фактически выполнялась по-разному. Но я понятия не имею, почему это могло быть так. Я подозреваю, что это более тесно связано с chrs(), чем с bits_strings().
Я не понимаю, почему переопределение chrs(), кажется, непредсказуемо влияет на вывод профилировщика.