Пытаюсь найти узкие места в скрипте Python при помощи cProfile. Однако его результаты меня очень удивляют.
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.072 0.072 <string>:1(<module>)
4 0.000 0.000 0.000 0.000 <string>:1(__new__)
1 0.000 0.000 0.004 0.004 app.py:411(select_single_file_for_processing)
1 0.000 0.000 0.001 0.001 app.py:450(update_processing_status)
1 0.000 0.000 0.072 0.072 app.py:471(worker)
2 0.000 0.000 0.000 0.000 pathlib.py:1001(_init)
4 0.000 0.000 0.000 0.000 pathlib.py:135(splitroot)
2 0.000 0.000 0.000 0.000 pathlib.py:53(parse_parts)
2 0.000 0.000 0.000 0.000 pathlib.py:624(_parse_args)
2 0.000 0.000 0.000 0.000 pathlib.py:644(_from_parts)
1 0.000 0.000 0.000 0.000 pathlib.py:667(_format_parsed_parts)
1 0.000 0.000 0.000 0.000 pathlib.py:684(__str__)
1 0.000 0.000 0.000 0.000 pathlib.py:770(name)
2 0.000 0.000 0.000 0.000 pathlib.py:991(__new__)
7 0.000 0.000 0.000 0.000 utf_8.py:15(decode)
1 0.000 0.000 0.056 0.056 xmlprocessing.py:1331(prepare_to_insert)
1 0.000 0.000 0.000 0.000 xmlprocessing.py:145(xpath_one_level)
1 0.000 0.000 0.000 0.000 xmlprocessing.py:147(<listcomp>)
3 0.000 0.000 0.000 0.000 xmlprocessing.py:2511(insert_prepare)
3 0.000 0.000 0.056 0.019 xmlprocessing.py:2527(save_to_ora)
1 0.000 0.000 0.000 0.000 xmlprocessing.py:507(xPath_contracts)
1 0.008 0.008 0.065 0.065 xmlprocessing.py:760(parse_xml)
6 0.000 0.000 0.000 0.000 {built-in method __new__ of type object at 0x00007FFB08E56D30}
7 0.000 0.000 0.000 0.000 {built-in method _codecs.utf_8_decode}
1 0.000 0.000 0.072 0.072 {built-in method builtins.exec}
8 0.000 0.000 0.000 0.000 {built-in method builtins.isinstance}
16 0.000 0.000 0.000 0.000 {built-in method builtins.len}
22 0.014 0.001 0.014 0.001 {built-in method builtins.print}
4 0.000 0.000 0.000 0.000 {built-in method nt.fspath}
12 0.000 0.000 0.000 0.000 {built-in method sys.intern}
20 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
3 0.016 0.005 0.016 0.005 {method 'commit' of 'cx_Oracle.Connection' objects}
2 0.003 0.002 0.003 0.002 {method 'commit' of 'psycopg2.extensions.connection' objects}
2 0.000 0.000 0.000 0.000 {method 'cursor' of 'psycopg2.extensions.connection' objects}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
3 0.029 0.010 0.029 0.010 {method 'execute' of 'cx_Oracle.Cursor' objects}
3 0.001 0.000 0.001 0.000 {method 'execute' of 'psycopg2.extensions.cursor' objects}
1 0.000 0.000 0.000 0.000 {method 'fetchone' of 'psycopg2.extensions.cursor' objects}
3 0.000 0.000 0.000 0.000 {method 'format' of 'str' objects}
1 0.000 0.000 0.000 0.000 {method 'join' of 'str' objects}
117 0.000 0.000 0.000 0.000 {method 'lower' of 'str' objects}
2 0.000 0.000 0.000 0.000 {method 'lstrip' of 'str' objects}
3 0.000 0.000 0.000 0.000 {method 'prepare' of 'cx_Oracle.Cursor' objects}
5 0.000 0.000 0.000 0.000 {method 'replace' of 'str' objects}
2 0.000 0.000 0.000 0.000 {method 'reverse' of 'list' objects}
3 0.000 0.000 0.000 0.000 {method 'split' of 'str' objects}
Казалось бы все функции отрабатывают очень быстро. Запускаю скрипт через ptime (аналог time из unix - измеряет время работы приложения до завершения) и получаю:
Execution time: 1.006 s
Тоесть уже целая секунда. И никак не могу понять. Почему время не сходится. Оставшееся время на инициализацию Питона уходит?