[profiling] Profile/analyze runtime startup (and shutdown). #75

ericsnowcurrently · 2021-07-27T16:43:25Z

Fine-grained profile info for startup will be helpful for knowing where to focus effort. Steps:

run perf to get a flamegraph (see [profiling] Add profiling instrumentation centered on the eval loop #25 (comment).)
review where time is spent
look for low-hanging fruit
discuss with the team

ericsnowcurrently · 2021-07-27T17:00:34Z

The 100,000 hz flamegraph for ./python -c pass on a non-debug build (see #25 (comment).) is a good first step.

Based on the flame graph (ignoring "perf"), ./python -c pass (with 5 warmups) spends time like this:

62% - python
- 55.9% - main() -> pymain_main()
  - 47.7% - pymain_init() -> Py_InitializeFromConfig()
    - 39.4% - pyinit_main() -> init_interp_main()
      - 16.3% - init_import_site() -> deep stack with 4+ imports and many Python calls
      - 8% - init_importlib_external() -> deep stack with 2+ imports and many Python calls
        
        5% - ... -> builtin_exec()
        
        3% - ... -> PyMarshal_ReadObjectFromString()
      - 7.7% - _PyUnicode_InitEncodings() -> deep stack with 2+ imports and many Python calls
      - 7.3% - init_sys_streams() -> deep stack with 3+ imports and many Python calls
    - 8.1% - pyinit_core() ->pyinit_config() -> pycore_interp_init() -> pycore_init_types()
  - 8.2% - Py_RunMain()
    - 0% - <run "pass">
    - 8.2% - PyFinalize_Ex() -> finalize_modules()
- 6.1% - <process overhead, e.g. loader>
37% - swapper (CPU is idle, e.g. blocking on IO)

ericsnowcurrently · 2021-07-27T17:12:38Z

With the "time" command we can see how long ./python -c pass takes in clock time:

$ time sudo perf record -g -a -F max -- ./python -c pass
info: Using a maximum frequency rate of 100,000 Hz
[ perf record: Woken up 4 times to write data ]
[ perf record: Captured and wrote 1.140 MB perf.data (2057 samples) ]

real    0m1.135s
user    0m0.303s
sys     0m0.812s
$ time ./cpython/python -c pass

real    0m0.026s
user    0m0.025s
sys     0m0.000s

Combining that with the flamegraph info we can approximate clock time spent:

15.5 ms - python
- 14 ms - main()
  - 11.9 ms - pymain_init()
    - 9.9 ms - pyinit_main()
      - 4.1 ms - init_import_site()
      - 2 ms - init_importlib_external()
        
        1.25 ms - builtin_exec()
        
        0.75 ms - PyMarshal_ReadObjectFromString()
      - 1.9 ms - _PyUnicode_InitEncodings()
      - 1.8 ms - init_sys_streams()
    - 2 ms - pyinit_core()
  - 2 ms - Py_RunMain()
    - 0 ms - <run "pass">
    - 2 ms - PyFinalize_Ex()
- 1.5 ms - <process overhead>
9.2 ms - swapper

FTR, if we skip the site module:

$ time ./python -S -c pass

real    0m0.017s
user    0m0.017s
sys     0m0.000s

...and the flamegraph is clearly different.

ericsnowcurrently · 2021-07-27T17:22:26Z

Possible improvements:

spend much less time in "swapper" (i.e. blocking on IO)
- by not opening any files?
make importing the site module (init_import_site()) cheaper
smaller C call stacks?
do not bother finalizing (some) modules when finalizing the runtime

Other todo items:

figure out what is really happening in "swapper"
does "swapper" % stay relatively constant for different workloads?

methane · 2021-07-28T05:22:46Z

Make codecs lightweight
- Initialize codecs registry only with builtin codecs.
- Import encodings module lazily when codec not found in builtin codecs.

ericsnowcurrently · 2021-07-28T14:38:20Z

FTR, here are all the symbols with at least one sample, sorted by #samples.

Samples: 1K of event 'cycles', Event count (approx.): 35154192
  Children  Overhead       Samples       sys       usr  Symbol
+    4.24%     3.10%            46     0.00%     3.10%  [.] _Py_dict_lookup    ◆
+    4.09%     2.00%            28     0.00%     2.00%  [.] pymalloc_alloc     ▒
+    1.99%     1.99%            26     0.00%     1.99%  [.] siphash24          ▒
+   28.47%     1.28%            24     0.00%     1.28%  [.] _PyEval_EvalFrameDe▒
+    2.71%     1.42%            21     0.00%     1.42%  [.] _PyObject_IS_GC    ▒
+    1.43%     1.35%            21     0.00%     1.35%  [.] dictkeys_get_index ▒
+    1.37%     1.37%            20     0.00%     1.37%  [.] PyType_HasFeature  ▒
+    2.42%     1.08%            17     0.00%     1.08%  [.] insertdict         ▒
+    2.99%     1.00%            15     0.00%     1.00%  [.] PyUnicode_New      ▒
+    6.84%     0.96%            14     0.00%     0.96%  [.] PyDict_SetDefault  ▒
+    1.55%     1.19%            14     1.19%     0.00%  [k] filemap_map_pages  ▒
+    1.96%     0.97%            13     0.00%     0.97%  [.] _Py_DECREF         ▒
+    0.98%     0.89%            13     0.00%     0.89%  [.] ascii_decode       ▒
+    0.84%     0.84%            12     0.00%     0.84%  [.] slotptr            ▒
+    7.71%     0.62%            11     0.00%     0.62%  [.] r_object           ▒
+    0.58%     0.58%            11     0.00%     0.58%  [.] ucs1lib_find_max_ch▒
+    7.74%     0.69%            10     0.00%     0.69%  [.] _Py_Dealloc        ▒
+    1.67%     0.72%            10     0.00%     0.72%  [.] pymalloc_pool_exten▒
+    0.59%     0.54%            10     0.00%     0.54%  [.] resolve_slotdups   ▒
+    1.91%     0.45%             9     0.00%     0.45%  [.] _PyType_Lookup     ▒
     0.73%     0.73%             9     0.73%     0.00%  [k] clear_page_erms    ▒
+    0.63%     0.58%             9     0.00%     0.58%  [.] PyType_HasFeature  ▒
+    0.56%     0.56%             9     0.00%     0.56%  [.] dictkeys_set_index ▒
+    5.03%     0.62%             8     0.00%     0.62%  [.] _Py_DECREF         ▒
+    3.97%     0.51%             8     0.00%     0.51%  [.] unicode_decode_utf8▒
+    2.29%     0.54%             8     0.00%     0.54%  [.] visit_decref       ▒
+    1.96%     0.60%             8     0.00%     0.60%  [.] dict_traverse      ▒
+    1.36%     0.63%             8     0.00%     0.63%  [.] pymalloc_free      ▒
     0.55%     0.49%             8     0.00%     0.49%  [.] find_empty_slot    ▒
+    4.63%     0.45%             7     0.00%     0.45%  [.] _PyObject_Malloc   ▒
+    3.62%     0.47%             7     0.00%     0.47%  [.] subtract_refs      ▒
     0.79%     0.49%             7     0.00%     0.49%  [.] build_indices      ▒
     0.58%     0.47%             7     0.00%     0.47%  [.] r_long             ▒
     0.44%     0.44%             7     0.00%     0.44%  [.] _Py_IS_TYPE        ▒
+   28.43%     0.30%             6     0.00%     0.30%  [.] call_function      ▒
+    8.29%     0.40%             6     0.00%     0.40%  [.] PyUnicode_InternInP▒
+    5.52%     0.35%             6     0.00%     0.35%  [.] _PyObject_GC_Alloc ▒
+    1.54%     0.32%             6     0.00%     0.32%  [.] _PyDict_GetItem_Kno▒
+    1.43%     0.50%             6     0.00%     0.50%  [.] _Py_DECREF         ▒
     0.52%     0.52%             6     0.52%     0.00%  [k] native_irq_return_i▒
     0.45%     0.45%             6     0.00%     0.45%  [.] arena_map_get      ▒
+    0.86%     0.34%             5     0.00%     0.34%  [.] PyObject_GC_Del    ▒
     0.34%     0.34%             5     0.00%     0.34%  [.] _Py_REFCNT         ▒
     0.33%     0.33%             5     0.33%     0.00%  [k] _raw_spin_lock     ▒
     0.33%     0.33%             5     0.00%     0.33%  [.] r_byte             ▒
+    5.23%     0.33%             4     0.00%     0.33%  [.] _Py_XDECREF        ▒
+    2.02%     0.29%             4     0.00%     0.29%  [.] move_unreachable   ▒
+    2.01%     0.21%             4     0.00%     0.21%  [.] find_name_in_mro   ▒
+    1.78%     0.25%             4     0.00%     0.25%  [.] dictresize         ▒
+    0.95%     0.19%             4     0.00%     0.19%  [.] _Py_DECREF         ▒
+    0.86%     0.20%             4     0.00%     0.20%  [.] _PyObjectDict_SetIt▒
     0.79%     0.34%             4     0.00%     0.34%  [.] arena_map_is_used  ▒
     0.60%     0.31%             4     0.00%     0.31%  [.] _Py_DECREF         ▒
     0.39%     0.31%             4     0.00%     0.31%  [.] gc_get_refs        ▒
     0.39%     0.32%             4     0.00%     0.32%  [.] untrack_tuples     ▒
     0.36%     0.36%             4     0.36%     0.00%  [k] __mod_lruvec_state ▒
     0.35%     0.35%             4     0.35%     0.00%  [k] vma_interval_tree_i▒
     0.35%     0.35%             4     0.00%     0.35%  [.] _PyType_InitCache  ▒
     0.35%     0.35%             4     0.35%     0.00%  [k] unlock_page        ▒
     0.27%     0.27%             4     0.00%     0.27%  [.] _PyRuntimeState_Get▒
     0.23%     0.23%             4     0.00%     0.23%  [.] PyType_HasFeature  ▒
     0.23%     0.23%             4     0.00%     0.23%  [.] 0x000000000018ead1 ▒
+    5.15%     0.26%             3     0.00%     0.26%  [.] free_keys_object   ▒
+    4.74%     0.19%             3     0.19%     0.00%  [k] __handle_mm_fault  ▒
+    4.52%     0.25%             3     0.00%     0.25%  [.] add_operators      ▒
+    4.05%     0.20%             3     0.00%     0.20%  [.] _PyObject_GC_New   ▒
+    2.63%     0.19%             3     0.00%     0.19%  [.] unicode_dealloc    ▒
+    2.29%     0.16%             3     0.00%     0.16%  [.] update_one_slot    ▒
+    1.76%     0.25%             3     0.00%     0.25%  [.] _Py_XDECREF        ▒
+    1.63%     0.26%             3     0.00%     0.26%  [.] type_cache_clear   ▒
+    1.28%     0.24%             3     0.00%     0.24%  [.] visit_reachable    ▒
+    1.19%     0.23%             3     0.23%     0.00%  [k] __alloc_pages_nodem▒
+    0.89%     0.19%             3     0.00%     0.19%  [.] _Py_DECREF         ▒
+    0.83%     0.20%             3     0.00%     0.20%  [.] allocate_from_new_p▒
     0.64%     0.20%             3     0.00%     0.20%  [.] _PyObject_Init     ▒
     0.62%     0.27%             3     0.27%     0.00%  [k] zap_pte_range.isra.▒
     0.46%     0.23%             3     0.23%     0.00%  [k] mem_cgroup_try_char▒
     0.46%     0.24%             3     0.00%     0.24%  [.] inherit_slots      ▒
     0.43%     0.17%             3     0.00%     0.17%  [.] tupletraverse      ▒
     0.42%     0.25%             3     0.00%     0.25%  [.] PyLong_FromUnsigned▒
     0.40%     0.23%             3     0.00%     0.23%  [.] _PyInterpreterState▒
     0.27%     0.27%             3     0.27%     0.00%  [k] sync_regs          ▒
     0.26%     0.26%             3     0.00%     0.26%  [.] _PyDict_Next       ▒
     0.25%     0.20%             3     0.00%     0.20%  [.] init_code          ▒
     0.25%     0.25%             3     0.00%     0.25%  [.] gc_list_size       ▒
     0.22%     0.22%             3     0.00%     0.22%  [.] _Py_SET_REFCNT     ▒
     0.21%     0.15%             3     0.00%     0.15%  [.] _Py_DECREF         ▒
     0.20%     0.20%             3     0.00%     0.20%  [.] _PyRuntimeState_Get▒
     0.20%     0.20%             3     0.00%     0.20%  [.] _PyRuntimeState_Get▒
     0.19%     0.19%             3     0.00%     0.19%  [.] _Py_INCREF         ▒
     0.19%     0.19%             3     0.00%     0.19%  [.] _PyRuntimeState_Get▒
     0.16%     0.16%             3     0.00%     0.16%  [.] _Py_IS_TYPE        ▒
     0.16%     0.16%             3     0.00%     0.16%  [.] PyType_HasFeature  ▒
     0.16%     0.16%             3     0.00%     0.16%  [.] _Py_INCREF         ▒
+    5.67%     0.17%             2     0.00%     0.17%  [.] descr_new          ▒
+    3.19%     0.13%             2     0.00%     0.13%  [.] PyDict_SetItem     ▒
+    2.72%     0.17%             2     0.00%     0.17%  [.] PyObject_SetAttr   ▒
+    2.47%     0.17%             2     0.00%     0.17%  [.] PyObject_Hash      ▒
+    2.39%     0.10%             2     0.00%     0.10%  [.] fixup_slot_dispatch▒
+    2.25%     0.17%             2     0.00%     0.17%  [.] func_clear         ▒
+    2.24%     0.14%             2     0.00%     0.14%  [.] unicode_hash       ▒
+    1.96%     0.13%             2     0.00%     0.13%  [.] PyCMethod_New      ▒
+    1.66%     0.11%             2     0.00%     0.11%  [.] tuple_alloc        ▒
+    1.57%     0.15%             2     0.00%     0.15%  [.] PyObject_Free      ▒
+    1.56%     0.14%             2     0.14%     0.00%  [k] do_anonymous_page  ▒
+    1.48%     0.09%             2     0.00%     0.09%  [.] PyObject_GetAttr   ▒
+    1.45%     0.11%             2     0.00%     0.11%  [.] PyFunction_NewWithQ▒
+    1.29%     0.14%             2     0.00%     0.14%  [.] PyType_GenericAlloc▒
+    1.14%     0.17%             2     0.00%     0.17%  [.] _PyObject_GC_NewVar▒
+    0.80%     0.17%             2     0.00%     0.17%  [.] delitem_common     ▒
+    0.78%     0.17%             2     0.00%     0.17%  [.] _PyUnicode_FromId  ▒
     0.57%     0.17%             2     0.00%     0.17%  [.] insert_to_emptydict▒
     0.56%     0.10%             2     0.00%     0.10%  [.] _PyEvalFrameClearAn▒
     0.38%     0.13%             2     0.00%     0.13%  [.] new_keys_object    ▒
     0.35%     0.15%             2     0.00%     0.15%  [.] _PyInterpreterState▒
     0.35%     0.10%             2     0.00%     0.10%  [.] _Py_XDECREF        ▒
     0.35%     0.14%             2     0.00%     0.14%  [.] intern_strings     ▒
     0.32%     0.13%             2     0.00%     0.13%  [.] _PyInterpreterState▒
     0.28%     0.14%             2     0.14%     0.00%  [k] __pagevec_lru_add_f▒
     0.27%     0.18%             2     0.00%     0.18%  [.] _dl_addr           ▒
     0.26%     0.17%             2     0.00%     0.17%  [.] untrack_dicts      ▒
     0.25%     0.10%             2     0.00%     0.10%  [.] _Py_DECREF         ▒
     0.23%     0.15%             2     0.15%     0.00%  [k] try_charge         ▒
     0.23%     0.14%             2     0.00%     0.14%  [.] _PyObject_Init     ▒
     0.20%     0.12%             2     0.00%     0.12%  [.] _Py_INCREF         ▒
     0.18%     0.18%             2     0.00%     0.18%  [.] 0x000000000000c132 ▒
     0.18%     0.18%             2     0.00%     0.18%  [.] 0x000000000000e2e0 ▒
     0.18%     0.18%             2     0.18%     0.00%  [k] page_add_file_rmap ▒
     0.17%     0.17%             2     0.00%     0.17%  [.] type_is_gc         ▒
     0.17%     0.17%             2     0.00%     0.17%  [.] 0x000000000009b8bc ▒
     0.17%     0.17%             2     0.00%     0.17%  [.] 0x000000000018b4ab ▒
     0.17%     0.17%             2     0.00%     0.17%  [.] _PyType_HasFeature ▒
     0.17%     0.17%             2     0.00%     0.17%  [.] _Py_NewRef         ▒
     0.17%     0.17%             2     0.00%     0.17%  [.] _PyRuntimeState_Get▒
     0.17%     0.17%             2     0.00%     0.17%  [.] dictkeys_incref    ▒
     0.17%     0.17%             2     0.00%     0.17%  [.] type_mro_modified  ▒
     0.17%     0.11%             2     0.00%     0.11%  [.] _PyType_HasFeature ▒
     0.14%     0.14%             2     0.14%     0.00%  [k] vmacache_find      ▒
     0.14%     0.14%             2     0.00%     0.14%  [.] 0x000000000018b6a7 ▒
     0.14%     0.14%             2     0.14%     0.00%  [k] __count_memcg_event▒
     0.14%     0.14%             2     0.00%     0.14%  [.] _Py_DECREF         ▒
     0.14%     0.14%             2     0.00%     0.14%  [.] all_name_chars     ▒
     0.14%     0.14%             2     0.00%     0.14%  [.] 0x000000000018e6f7 ▒
     0.12%     0.12%             2     0.00%     0.12%  [.] PyObject_GC_UnTrack▒
     0.12%     0.12%             2     0.00%     0.12%  [.] _PyObject_GC_TRACK ◆
     0.11%     0.11%             2     0.00%     0.11%  [.] long_hash          ▒
     0.11%     0.11%             2     0.00%     0.11%  [.] _Py_INCREF         ▒
     0.10%     0.10%             2     0.00%     0.10%  [.] _PyErr_Occurred    ▒
     0.10%     0.10%             2     0.00%     0.10%  [.] PyType_HasFeature  ▒
     0.09%     0.09%             2     0.00%     0.09%  [.] _Py_CheckFunctionRe▒
+   28.43%     0.04%             1     0.00%     0.04%  [.] object_vacall      ▒
+   19.42%     0.09%             1     0.00%     0.09%  [.] pycore_interp_init ▒
+   12.66%     0.08%             1     0.00%     0.08%  [.] PyType_Ready       ▒
+    6.15%     0.08%             1     0.00%     0.08%  [.] deduce_unreachable ▒
+    5.22%     0.09%             1     0.09%     0.00%  [k] __do_page_fault    ▒
+    5.14%     0.05%             1     0.00%     0.05%  [.] type_call          ▒
+    5.08%     0.09%             1     0.09%     0.00%  [k] do_user_addr_fault ▒
+    4.42%     0.05%             1     0.00%     0.05%  [.] PyObject_Malloc    ▒
+    4.17%     0.06%             1     0.00%     0.06%  [.] PyDict_SetItemStrin▒
+    3.84%     0.06%             1     0.00%     0.06%  [.] PyUnicode_FromStrin▒
+    2.46%     0.04%             1     0.00%     0.04%  [.] PyObject_GenericSet▒
+    2.35%     0.09%             1     0.00%     0.09%  [.] _PyObject_GenericSe▒
+    2.32%     0.08%             1     0.00%     0.08%  [.] _Py_DECREF         ▒
+    2.25%     0.08%             1     0.00%     0.08%  [.] func_dealloc       ▒
+    2.16%     0.08%             1     0.00%     0.08%  [.] _Py_HashBytes      ▒
+    2.08%     0.08%             1     0.00%     0.08%  [.] pysiphash          ▒
+    1.79%     0.08%             1     0.00%     0.08%  [.] PyDict_DelItem     ▒
+    1.58%     0.06%             1     0.00%     0.06%  [.] PyModule_AddIntCons▒
+    1.40%     0.05%             1     0.00%     0.05%  [.] _PyObject_Free     ▒
+    1.36%     0.06%             1     0.00%     0.06%  [.] _PyObject_Call_Prep▒
+    1.31%     0.08%             1     0.00%     0.08%  [.] PyDescr_NewMethod  ▒
+    1.17%     0.05%             1     0.00%     0.05%  [.] _PyUnicode_FromUCS1▒
+    0.88%     0.08%             1     0.08%     0.00%  [k] get_page_from_freel▒
+    0.85%     0.08%             1     0.00%     0.08%  [.] PyTuple_New        ▒
+    0.80%     0.05%             1     0.00%     0.05%  [.] PyBytes_FromStringA▒
+    0.78%     0.09%             1     0.00%     0.09%  [.] func_traverse      ▒
+    0.67%     0.05%             1     0.00%     0.05%  [.] type_ready_add_subc▒
+    0.62%     0.06%             1     0.00%     0.06%  [.] type_add_getset    ▒
     0.51%     0.08%             1     0.00%     0.08%  [.] PyDict_Contains    ▒
     0.51%     0.08%             1     0.00%     0.08%  [.] _Py_XDECREF        ▒
     0.45%     0.05%             1     0.00%     0.05%  [.] get_tuple_state    ▒
     0.45%     0.04%             1     0.00%     0.04%  [.] PyObject_CallOneArg▒
     0.44%     0.09%             1     0.09%     0.00%  [k] __do_munmap        ▒
     0.43%     0.09%             1     0.00%     0.09%  [.] _PyUnicode_ClearInt▒
     0.43%     0.09%             1     0.09%     0.00%  [k] pagevec_lru_move_fn▒
     0.42%     0.08%             1     0.00%     0.08%  [.] mro_implementation ▒
     0.40%     0.06%             1     0.06%     0.00%  [k] __lru_cache_add    ▒
     0.39%     0.07%             1     0.00%     0.07%  [.] PyDict_GetItemWithE▒
     0.36%     0.09%             1     0.09%     0.00%  [k] alloc_set_pte      ▒
     0.36%     0.08%             1     0.00%     0.08%  [.] PyObject_ClearWeakR▒
     0.35%     0.09%             1     0.09%     0.00%  [k] page_remove_rmap   ▒
     0.35%     0.05%             1     0.00%     0.05%  [.] _PyFrame_Clear     ▒
     0.33%     0.08%             1     0.00%     0.08%  [.] _PyObject_InitVar  ▒
     0.32%     0.07%             1     0.00%     0.07%  [.] object_dealloc     ▒
     0.31%     0.05%             1     0.00%     0.05%  [.] list_resize        ▒
     0.29%     0.05%             1     0.00%     0.05%  [.] intern_string_const▒
     0.28%     0.08%             1     0.00%     0.08%  [.] _PyThreadState_GET ▒
     0.28%     0.05%             1     0.00%     0.05%  [.] _Py_NewReference   ▒
     0.27%     0.06%             1     0.00%     0.06%  [.] _PyDict_GetItemIdWi▒
     0.27%     0.09%             1     0.00%     0.09%  [.] setlocale          ▒
     0.25%     0.06%             1     0.00%     0.06%  [.] _PyObject_GetMethod▒
     0.24%     0.05%             1     0.00%     0.05%  [.] PyErr_Occurred     ▒
     0.22%     0.07%             1     0.00%     0.07%  [.] type_new_set_names ▒
     0.19%     0.09%             1     0.00%     0.09%  [.] meth_dealloc       ▒
     0.19%     0.06%             1     0.00%     0.06%  [.] _PyObject_Init     ▒
     0.19%     0.05%             1     0.00%     0.05%  [.] _PyObject_New      ▒
     0.19%     0.08%             1     0.00%     0.08%  [.] _PyErr_Restore     ▒
     0.17%     0.09%             1     0.00%     0.09%  [.] module_dealloc     ▒
     0.17%     0.07%             1     0.00%     0.07%  [.] vgetargs1          ▒
     0.17%     0.06%             1     0.00%     0.06%  [.] initialize_locals  ▒
     0.16%     0.05%             1     0.00%     0.05%  [.] _Py_XDECREF        ▒
     0.15%     0.06%             1     0.00%     0.06%  [.] type_traverse      ▒
     0.15%     0.09%             1     0.00%     0.09%  [.] _PyType_HasFeature ▒
     0.14%     0.06%             1     0.00%     0.06%  [.] _Py_SET_TYPE       ▒
     0.12%     0.06%             1     0.00%     0.06%  [.] _PyInterpreterState▒
     0.11%     0.06%             1     0.00%     0.06%  [.] _io_open           ▒
     0.11%     0.06%             1     0.00%     0.06%  [.] _PyThreadState_Push▒
     0.10%     0.05%             1     0.00%     0.05%  [.] convertsimple      ▒
     0.10%     0.04%             1     0.00%     0.04%  [.] PyMem_Malloc       ▒
     0.10%     0.05%             1     0.00%     0.05%  [.] AttributeError_init▒
     0.10%     0.05%             1     0.00%     0.05%  [.] PyObject_DelItem   ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] ext4_release_file  ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000db42 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x00000000000209f5 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x0000000000026f60 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000b7b0 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000c0eb ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000b58f ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000e304 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000b824 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000b82d ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] copy_page          ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000dc2c ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000c123 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x0000000000026dea ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] strchrnul          ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] __do_fault         ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000de4b ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] xas_start          ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000b4c7 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] __tunable_get_val  ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x0000000000034951 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000e2f9 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] PyConfig_Clear     ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000009b3ce ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] config_init_warnopt▒
     0.09%     0.09%             1     0.09%     0.00%  [k] __x64_sys_getrandom▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _PyGC_InitState    ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x00000000000133e8 ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] security_file_permi▒
     0.09%     0.09%             1     0.09%     0.00%  [k] __rb_insert_augment▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _PyRuntimeState_Get▒
     0.09%     0.09%             1     0.09%     0.00%  [k] kmem_cache_free    ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] memcg_kmem_get_cach▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000000773e ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] down_write         ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] __fget_light       ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x00000000000077a1 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _Py_IS_TYPE        ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _Py_DECREF         ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _PyDict_MaybeUntrac▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _Py_SET_REFCNT     ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] acct_collect       ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x0000000000099c22 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000001cebb ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000018eb99 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x0000000000011e51 ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] fsnotify_destroy_ma▒
     0.09%     0.09%             1     0.09%     0.00%  [k] perf_iterate_sb    ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] touch_atime        ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] get_mem_cgroup_from▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _Py_INCREF         ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x000000000018b675 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] gc_reset_refs      ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] binarysort         ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] set_add_entry      ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] flush_signal_handle▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _IO_default_xsputn ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] 0x0000000000187dc0 ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] _PyDict_ClearFreeLi▒
     0.09%     0.09%             1     0.00%     0.09%  [.] make_version_info  ▒
     0.09%     0.09%             1     0.00%     0.09%  [.] PyType_IsSubtype   ▒
     0.09%     0.09%             1     0.09%     0.00%  [k] page_counter_try_ch▒
     0.08%     0.08%             1     0.00%     0.08%  [.] 0x000000000018b6d4 ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] 0x0000000000187e3f ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] _PyObject_GC_TRACK ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] 0x000000000018e70e ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] type_ready_post_che▒
     0.08%     0.08%             1     0.00%     0.08%  [.] _PyRuntimeState_Get▒
     0.08%     0.08%             1     0.00%     0.08%  [.] gc_is_collecting   ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] _Py_SET_SIZE       ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] PyType_HasFeature  ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] 0x000000000018e68b ▒
     0.08%     0.08%             1     0.00%     0.08%  [.] _PyObject_GC_UNTRAC▒
     0.08%     0.08%             1     0.00%     0.08%  [.] 0x000000000009b7a6 ▒
     0.08%     0.08%             1     0.08%     0.00%  [k] pick_next_task_stop▒
     0.07%     0.07%             1     0.00%     0.07%  [.] _Py_LeaveRecursiveC▒
     0.07%     0.07%             1     0.00%     0.07%  [.] PyTuple_GetItem    ▒
     0.07%     0.07%             1     0.00%     0.07%  [.] weakref___new__    ▒
     0.07%     0.07%             1     0.00%     0.07%  [.] object_init_subclas▒
     0.07%     0.07%             1     0.00%     0.07%  [.] _PyRuntimeState_Get▒
     0.07%     0.07%             1     0.00%     0.07%  [.] _Py_INCREF         ▒
     0.07%     0.07%             1     0.00%     0.07%  [.] _PyTuple_MaybeUntra▒
     0.07%     0.07%             1     0.00%     0.07%  [.] _Py_IS_TYPE        ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] __PyLong_GetSmallIn▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _Py_INCREF         ◆
     0.06%     0.06%             1     0.00%     0.06%  [.] gc_list_remove     ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _PyThreadState_GET ▒
     0.06%     0.06%             1     0.06%     0.00%  [k] mem_cgroup_page_lru▒
     0.06%     0.06%             1     0.00%     0.06%  [.] malloc             ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _Py_INCREF         ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _PyUnicode_JoinArra▒
     0.06%     0.06%             1     0.00%     0.06%  [.] builtin_len        ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] 0x0000000000186b68 ▒
     0.06%     0.06%             1     0.06%     0.00%  [k] rmqueue            ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _PyObject_GC_TRACK ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] findchar           ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] 0x000000000009b7fa ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _PyUnicodeWriter_In▒
     0.06%     0.06%             1     0.00%     0.06%  [.] 0x000000000018e6df ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _PyRuntimeState_Get▒
     0.06%     0.06%             1     0.06%     0.00%  [k] up_read            ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] init_shape_strides ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] long_compare       ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _Py_SET_SIZE       ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _PyThreadState_PopF▒
     0.06%     0.06%             1     0.00%     0.06%  [.] 0x000000000009ac01 ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] r_string           ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _Py_SET_SIZE       ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] get_phys_pages     ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] 0x000000000018b6a0 ▒
     0.06%     0.06%             1     0.00%     0.06%  [.] _Py_IS_TYPE        ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_XINCREF        ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] 0x000000000018b7c0 ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyType_HasFeature ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] 0x00000000000999c0 ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_LeaveRecursiveC▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyType_CalculateMe▒
     0.05%     0.05%             1     0.00%     0.05%  [.] 0x000000000018e67d ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] type_new_get_bases ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] parse_varint       ▒
     0.05%     0.05%             1     0.05%     0.00%  [k] down_read_trylock  ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] PyLong_FromUnsigned▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_DECREF         ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] PyType_HasFeature  ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_SET_SIZE       ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] PyType_HasFeature  ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyObject_GC_UNTRAC▒
     0.05%     0.05%             1     0.00%     0.05%  [.] pthread_self       ▒
     0.05%     0.05%             1     0.05%     0.00%  [k] page_mapping       ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyObject_Init     ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_DECREF         ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_INCREF         ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] vgetargskeywords   ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_IS_TYPE        ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyObject_GetDictPt▒
     0.05%     0.05%             1     0.00%     0.05%  [.] asciilib_rfind_char▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_SET_TYPE       ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] PySlice_Unpack     ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_IS_TYPE        ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _GetSpecializedCach▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyDict_LoadGlobal ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] super_getattro     ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] type_mro_impl      ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] set_next           ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_INCREF         ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] 0x0000000000098a8e ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyType_Check      ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] method_output_as_li▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_INCREF         ▒
     0.05%     0.05%             1     0.05%     0.00%  [k] activate_task      ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _PyObject_TypeCheck▒
     0.05%     0.05%             1     0.00%     0.05%  [.] _Py_INCREF         ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] PyDTrace_FUNCTION_R▒
     0.05%     0.05%             1     0.00%     0.05%  [.] get_abc_state      ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] PySequence_GetItem ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] 0x000000000018ebb3 ▒
     0.05%     0.05%             1     0.00%     0.05%  [.] 0x000000000005a5b0 ▒
     0.04%     0.04%             1     0.00%     0.04%  [.] pthread_testcancel ▒
     0.04%     0.04%             1     0.00%     0.04%  [.] _PyThreadState_GET ▒
     0.04%     0.04%             1     0.04%     0.00%  [k] syscall_return_via_▒
     0.04%     0.04%             1     0.00%     0.04%  [.] descr_setcheck     ▒
     0.04%     0.04%             1     0.00%     0.04%  [.] _Py_MakeRecCheck   ▒

As expected, the results vary with each run, though the outcome is relatively consistent.

ericsnowcurrently · 2021-07-28T16:38:07Z

Also, I took a look at what shared objects are loaded:

Samples: 1K of event 'cycles', Event count (approx.): 38109535
  Children  Overhead       Samples  Shared Object
+   32.80%    32.12%           942  [kernel.kallsyms]
+   65.91%    61.79%           898  python
+   87.84%     2.82%            41  libc-2.31.so
+    5.07%     2.28%            28  ld-2.31.so
+    5.32%     0.19%             6  [unknown]
+    6.08%     0.33%             5  libpthread-2.31.so
     0.35%     0.27%             4  libsystemd-shared-245.so
+   16.50%     0.13%             2  perf
     0.06%     0.06%             1  systemd-journald
     0.17%     0.00%             0  libm-2.31.so

ericsnowcurrently · 2021-07-28T17:38:29Z

For completeness, here's strace info:

$ strace -c /home/esnow/perf-data/cpython/python -c pass
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 29.06    0.000127           2        63        11 stat
 20.37    0.000089          14         6           getdents64
  9.61    0.000042           1        28         2 openat
  8.47    0.000037           1        35           read
  8.01    0.000035           0        44           fstat
  7.78    0.000034           1        29           close
  4.81    0.000021           2         9           brk
  4.58    0.000020           0        30         3 lseek
  3.20    0.000014           0        31           mmap
  2.29    0.000010          10         1           sysinfo
  1.83    0.000008           0        19        13 ioctl
  0.00    0.000000           0         8           mprotect
  0.00    0.000000           0         3           munmap
  0.00    0.000000           0        68           rt_sigaction
  0.00    0.000000           0         1           rt_sigprocmask
  0.00    0.000000           0         8           pread64
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         3           dup
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         3           fcntl
  0.00    0.000000           0         1         1 readlink
  0.00    0.000000           0         1           getuid
  0.00    0.000000           0         1           getgid
  0.00    0.000000           0         1           geteuid
  0.00    0.000000           0         1           getegid
  0.00    0.000000           0         2         1 arch_prctl
  0.00    0.000000           0         1           gettid
  0.00    0.000000           0         1           futex
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
  0.00    0.000000           0         1           prlimit64
  0.00    0.000000           0         1           getrandom
------ ----------- ----------- --------- --------- ----------------
100.00    0.000437                   404        32 total

$ strace -c /home/esnow/perf-data/cpython/python -S -c pass
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0        21           read
  0.00    0.000000           0        21           close
  0.00    0.000000           0        32         7 stat
  0.00    0.000000           0        29           fstat
  0.00    0.000000           0        16         3 lseek
  0.00    0.000000           0        30           mmap
  0.00    0.000000           0         8           mprotect
  0.00    0.000000           0         2           munmap
  0.00    0.000000           0         7           brk
  0.00    0.000000           0        68           rt_sigaction
  0.00    0.000000           0         1           rt_sigprocmask
  0.00    0.000000           0        12         6 ioctl
  0.00    0.000000           0         8           pread64
  0.00    0.000000           0         1         1 access
  0.00    0.000000           0         3           dup
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         3           fcntl
  0.00    0.000000           0         1         1 readlink
  0.00    0.000000           0         1           sysinfo
  0.00    0.000000           0         2         1 arch_prctl
  0.00    0.000000           0         1           gettid
  0.00    0.000000           0         1           futex
  0.00    0.000000           0         4           getdents64
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0        20         2 openat
  0.00    0.000000           0         1           set_robust_list
  0.00    0.000000           0         1           prlimit64
  0.00    0.000000           0         1           getrandom
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                   297        21 total

methane · 2021-07-29T05:11:57Z

FWIW, we can use loop to stabilize perf result:

$ perf record -g bash -c "for i in {1..1000}; do ./python -c pass; done"

ericsnowcurrently · 2021-08-05T01:53:33Z

I've also used uftrace to get some data.

(for "python -c pass")
flamegraph

all calls, ordered by usage

(sorted by "self" time: not counting children)

  Total time   Self time       Calls  Function
  ==========  ==========  ==========  ====================
  Total time   Self time       Calls  Function
  ==========  ==========  ==========  ====================
  774.765 us  774.765 us       14874  memcpy
  416.849 us  416.849 us        7265  strlen
  416.443 us  416.443 us        6013  memset
  305.627 us  305.627 us        6332  memcmp
  210.861 us  210.861 us        3441  wcstombs
  135.739 us  135.739 us         413  readdir64
  159.312 us  128.386 us           1  list_stdlib_module_names
  368.594 us  127.032 us           1  _PySys_InitCore
  482.818 us  104.652 us           1  _PySys_Create
   84.888 us   84.888 us        1790  pthread_mutex_lock
   82.848 us   82.848 us          63  __xstat64
   82.172 us   82.172 us        1790  pthread_mutex_unlock
   74.791 us   74.791 us        1697  __errno_location
   74.102 us   74.102 us         710  mbstowcs
   58.134 us   58.134 us        1193  pthread_cond_signal
   81.101 us   56.812 us           3  qsort
   70.855 us   56.009 us          78  _PySys_GetObject
   55.225 us   55.225 us          26  read
   40.796 us   40.796 us           8  calloc
   38.062 us   38.062 us         725  wcscmp
   35.303 us   35.303 us         768  strcmp
   34.524 us   34.524 us          13  open64
   40.290 us   30.249 us           1  list_builtin_module_names
   26.700 us   26.700 us         113  realloc
   24.050 us   24.050 us         532  pthread_self
   31.927 us   23.890 us         148  _PyThreadState_GET
   39.521 us   22.007 us           1  calculate_open_pyenv
   21.811 us   21.811 us         325  strchr
   21.619 us   21.619 us           8  setlocale
   20.213 us   20.213 us         345  sem_post
   27.733 us   18.720 us           1  _PySys_UpdateConfig
   18.120 us   18.120 us           3  closedir
   99.333 us   14.719 us          77  PySys_GetObject
   14.264 us   14.264 us          16  close
   27.617 us   14.231 us           2  _Py_wstat
   17.496 us   13.881 us          86  should_audit
   13.682 us   13.682 us         233  strncmp
   13.462 us   13.462 us           2  localtime_r
   13.211 us   13.211 us           3  opendir
   13.094 us   13.094 us         220  sem_trywait
   13.073 us   13.073 us         191  wcslen
   12.695 us   12.695 us         221  strrchr
   43.053 us   10.849 us          58  PySys_Audit
   10.408 us   10.408 us         110  strncpy
   10.119 us   10.119 us          68  sigaction
    9.937 us    9.937 us          30  __fxstat64
   26.960 us    9.464 us          87  sys_audit_tstate
   23.561 us    8.636 us           1  calculate_pybuilddir
    8.337 us    8.337 us          19  isatty
    8.037 us    8.037 us         148  _PyRuntimeState_GetThreadState
    7.434 us    7.434 us         125  sem_wait
    7.004 us    7.004 us          98  _Py_DECREF
    6.698 us    6.698 us           3  fopen64
   13.841 us    6.443 us           1  resolve_symlinks
    6.217 us    6.217 us          14  strerror
    6.078 us    6.078 us          29  lseek64
    7.582 us    5.901 us           1  make_impl_info
    7.786 us    4.685 us           8  joinpath2
    4.528 us    4.528 us          30  getenv
    4.133 us    4.133 us          71  sem_init
    3.970 us    3.970 us          71  sem_destroy
    3.745 us    3.745 us          46  memrchr
    3.665 us    3.665 us           3  mmap64
    3.615 us    3.615 us          86  PyDTrace_AUDIT_ENABLED
    6.529 us    3.290 us           2  set_flags_from_config
    3.242 us    3.242 us           1  fread
    7.108 us    3.204 us           1  calculate_init
   12.280 us    3.190 us          29  _PySys_Audit
    4.560 us    3.084 us           3  sys_set_object_id
    3.795 us    3.010 us          35  _Py_XDECREF
    4.257 us    2.600 us           3  sys_set_object_str
    2.597 us    2.597 us           1  readlink
    2.425 us    2.425 us           1  floor
    2.270 us    2.270 us           1  munmap
    3.527 us    2.119 us           1  Py_GetBuildInfo
    2.096 us    2.096 us           1  confstr
    2.069 us    2.069 us          22  wcscat
    2.480 us    1.914 us           1  _PySys_SetPreliminaryStderr
    1.405 us    1.405 us           6  sys_set_object
    1.384 us    1.384 us           1  __libc_current_sigrtmin
    1.365 us    1.365 us           2  vsnprintf
    2.284 us    1.259 us           1  calculate_module_search_path
    1.251 us    1.251 us           3  dup
    1.036 us    1.036 us           1  fclose
    1.105 us    1.022 us           1  get_hash_info
    0.997 us    0.997 us          15  memmove
    1.638 us    0.966 us           3  joinpath
    2.913 us    0.958 us           9  _PyInterpreterState_GET
  118.785 us    0.923 us           1  calculate_path
    1.057 us    0.899 us           1  make_version_info
    1.943 us    0.898 us           2  sys_getfilesystemencoding_impl
    0.873 us    0.873 us           1  getrandom
    0.842 us    0.842 us           4  sys_get_object_id
    0.833 us    0.833 us           3  fcntl64
    2.546 us    0.831 us           4  _PySys_GetObjectId
    0.701 us    0.701 us           9  wcschr
    0.630 us    0.630 us           1  __libc_current_sigrtmax
    0.617 us    0.617 us           8  fileno
    0.820 us    0.606 us           1  calculate_program_impl
    0.595 us    0.595 us           8  wcscpy
  126.780 us    0.569 us           1  _PyPathConfig_Calculate
    5.832 us    0.537 us           3  PySys_SetObject
   14.805 us    0.532 us           1  calculate_argv0_path
   31.851 us    0.520 us           1  search_for_prefix
    0.770 us    0.513 us           2  safe_wcscpy
    2.982 us    0.485 us           1  make_flags
    5.846 us    0.477 us           3  _PySys_SetObjectId
   24.495 us    0.476 us           1  calculate_exec_prefix
   32.692 us    0.465 us           1  calculate_prefix
    0.835 us    0.445 us           1  sys_getfilesystemencodeerrors_impl
    0.537 us    0.413 us           1  calculate_set_prefix
    0.372 us    0.372 us           4  memchr
    0.926 us    0.369 us           1  _PySys_ClearAuditHooks
    0.368 us    0.368 us           3  wcsncpy
    0.524 us    0.356 us           2  reduce
    0.337 us    0.337 us           4  sigemptyset
    0.597 us    0.332 us           2  _Py_gitidentifier
    0.440 us    0.309 us           1  calculate_set_exec_prefix
    2.246 us    0.303 us           2  sys_getfilesystemencoding
    0.295 us    0.295 us           2  fflush
    0.418 us    0.280 us           1  _PySys_ReadPreinitWarnOptions
    0.247 us    0.247 us           1  geteuid
   27.857 us    0.240 us           2  isfile
    0.238 us    0.238 us           1  calculate_free
    0.220 us    0.220 us           2  _clear_preinit_entries
    0.215 us    0.215 us           1  sysconf
    1.964 us    0.209 us           1  calculate_zip_path
   13.059 us    0.207 us           1  ismodule
    0.204 us    0.204 us           2  pthread_cond_init
    0.183 us    0.183 us           1  pthread_key_delete
    0.170 us    0.170 us           4  _PyErr_Occurred
    0.987 us    0.167 us           1  calculate_program
    0.160 us    0.160 us           2  pthread_mutex_init
    0.155 us    0.155 us           1  syscall
    0.236 us    0.154 us           1  _PySys_ReadPreinitXOptions
    0.151 us    0.151 us           1  getegid
    0.145 us    0.145 us           1  getuid
   23.703 us    0.142 us           1  search_for_exec_prefix
   39.658 us    0.137 us           1  calculate_read_pyenv
    0.132 us    0.132 us           1  sys_create_xoptions_dict
    0.115 us    0.115 us           1  getgid
    0.944 us    0.109 us           1  sys_getfilesystemencodeerrors
    0.103 us    0.103 us           2  nl_langinfo
    0.093 us    0.093 us           1  pthread_key_create
    0.090 us    0.090 us           1  _PyRuntimeState_GetFinalizing
    0.084 us    0.084 us           2  _Py_gitversion
    0.070 us    0.070 us           1  _Py_INCREF
    0.067 us    0.067 us           1  pthread_condattr_init
    0.062 us    0.062 us           1  pthread_setspecific
    0.057 us    0.057 us           1  pthread_getspecific
    0.051 us    0.051 us           1  time
    0.047 us    0.047 us           1  pthread_condattr_setclock

(with percentages and totals)

  Total time     Total %   Self time      Self %       Calls     Calls %  Function
  ==========  ==========  ==========  ==========  ==========  ==========  ====================
  774.765 us      14.4 %  774.765 us      19.5 %       14874      29.1 %  memcpy
  416.849 us       7.7 %  416.849 us      10.5 %        7265      14.2 %  strlen
  416.443 us       7.7 %  416.443 us      10.5 %        6013      11.8 %  memset
  305.627 us       5.7 %  305.627 us       7.7 %        6332      12.4 %  memcmp
  210.861 us       3.9 %  210.861 us       5.3 %        3441       6.7 %  wcstombs
  135.739 us       2.5 %  135.739 us       3.4 %         413       0.8 %  readdir64
  159.312 us       3.0 %  128.386 us       3.2 %           1       0.0 %  list_stdlib_module_names
  368.594 us       6.8 %  127.032 us       3.2 %           1       0.0 %  _PySys_InitCore
  482.818 us       9.0 %  104.652 us       2.6 %           1       0.0 %  _PySys_Create
   84.888 us       1.6 %   84.888 us       2.1 %        1790       3.5 %  pthread_mutex_lock
   82.848 us       1.5 %   82.848 us       2.1 %          63       0.1 %  __xstat64
   82.172 us       1.5 %   82.172 us       2.1 %        1790       3.5 %  pthread_mutex_unlock
   74.791 us       1.4 %   74.791 us       1.9 %        1697       3.3 %  __errno_location
   74.102 us       1.4 %   74.102 us       1.9 %         710       1.4 %  mbstowcs
   58.134 us       1.1 %   58.134 us       1.5 %        1193       2.3 %  pthread_cond_signal
   81.101 us       1.5 %   56.812 us       1.4 %           3       0.0 %  qsort
   70.855 us       1.3 %   56.009 us       1.4 %          78       0.2 %  _PySys_GetObject
   55.225 us       1.0 %   55.225 us       1.4 %          26       0.1 %  read
   40.796 us       0.8 %   40.796 us       1.0 %           8       0.0 %  calloc
   38.062 us       0.7 %   38.062 us       1.0 %         725       1.4 %  wcscmp
   35.303 us       0.7 %   35.303 us       0.9 %         768       1.5 %  strcmp
   34.524 us       0.6 %   34.524 us       0.9 %          13       0.0 %  open64
   40.290 us       0.7 %   30.249 us       0.8 %           1       0.0 %  list_builtin_module_names
   26.700 us       0.5 %   26.700 us       0.7 %         113       0.2 %  realloc
   24.050 us       0.4 %   24.050 us       0.6 %         532       1.0 %  pthread_self
   31.927 us       0.6 %   23.890 us       0.6 %         148       0.3 %  _PyThreadState_GET
   39.521 us       0.7 %   22.007 us       0.6 %           1       0.0 %  calculate_open_pyenv
   21.811 us       0.4 %   21.811 us       0.5 %         325       0.6 %  strchr
   21.619 us       0.4 %   21.619 us       0.5 %           8       0.0 %  setlocale
   20.213 us       0.4 %   20.213 us       0.5 %         345       0.7 %  sem_post
   27.733 us       0.5 %   18.720 us       0.5 %           1       0.0 %  _PySys_UpdateConfig
   18.120 us       0.3 %   18.120 us       0.5 %           3       0.0 %  closedir
   99.333 us       1.8 %   14.719 us       0.4 %          77       0.2 %  PySys_GetObject
   14.264 us       0.3 %   14.264 us       0.4 %          16       0.0 %  close
   27.617 us       0.5 %   14.231 us       0.4 %           2       0.0 %  _Py_wstat
   17.496 us       0.3 %   13.881 us       0.3 %          86       0.2 %  should_audit
   13.682 us       0.3 %   13.682 us       0.3 %         233       0.5 %  strncmp
   13.462 us       0.2 %   13.462 us       0.3 %           2       0.0 %  localtime_r
   13.211 us       0.2 %   13.211 us       0.3 %           3       0.0 %  opendir
   13.094 us       0.2 %   13.094 us       0.3 %         220       0.4 %  sem_trywait
   13.073 us       0.2 %   13.073 us       0.3 %         191       0.4 %  wcslen
   12.695 us       0.2 %   12.695 us       0.3 %         221       0.4 %  strrchr
   43.053 us       0.8 %   10.849 us       0.3 %          58       0.1 %  PySys_Audit
   10.408 us       0.2 %   10.408 us       0.3 %         110       0.2 %  strncpy
   10.119 us       0.2 %   10.119 us       0.3 %          68       0.1 %  sigaction
    9.937 us       0.2 %    9.937 us       0.2 %          30       0.1 %  __fxstat64
   26.960 us       0.5 %    9.464 us       0.2 %          87       0.2 %  sys_audit_tstate
   23.561 us       0.4 %    8.636 us       0.2 %           1       0.0 %  calculate_pybuilddir
    8.337 us       0.2 %    8.337 us       0.2 %          19       0.0 %  isatty
    8.037 us       0.1 %    8.037 us       0.2 %         148       0.3 %  _PyRuntimeState_GetThreadState
    7.434 us       0.1 %    7.434 us       0.2 %         125       0.2 %  sem_wait
    7.004 us       0.1 %    7.004 us       0.2 %          98       0.2 %  _Py_DECREF
    6.698 us       0.1 %    6.698 us       0.2 %           3       0.0 %  fopen64
   13.841 us       0.3 %    6.443 us       0.2 %           1       0.0 %  resolve_symlinks
    6.217 us       0.1 %    6.217 us       0.2 %          14       0.0 %  strerror
    6.078 us       0.1 %    6.078 us       0.2 %          29       0.1 %  lseek64
    7.582 us       0.1 %    5.901 us       0.1 %           1       0.0 %  make_impl_info
    7.786 us       0.1 %    4.685 us       0.1 %           8       0.0 %  joinpath2
    4.528 us       0.1 %    4.528 us       0.1 %          30       0.1 %  getenv
    4.133 us       0.1 %    4.133 us       0.1 %          71       0.1 %  sem_init
    3.970 us       0.1 %    3.970 us       0.1 %          71       0.1 %  sem_destroy
    3.745 us       0.1 %    3.745 us       0.1 %          46       0.1 %  memrchr
    3.665 us       0.1 %    3.665 us       0.1 %           3       0.0 %  mmap64
    3.615 us       0.1 %    3.615 us       0.1 %          86       0.2 %  PyDTrace_AUDIT_ENABLED
    6.529 us       0.1 %    3.290 us       0.1 %           2       0.0 %  set_flags_from_config
    3.242 us       0.1 %    3.242 us       0.1 %           1       0.0 %  fread
    7.108 us       0.1 %    3.204 us       0.1 %           1       0.0 %  calculate_init
   12.280 us       0.2 %    3.190 us       0.1 %          29       0.1 %  _PySys_Audit
    4.560 us       0.1 %    3.084 us       0.1 %           3       0.0 %  sys_set_object_id
    3.795 us       0.1 %    3.010 us       0.1 %          35       0.1 %  _Py_XDECREF
    4.257 us       0.1 %    2.600 us       0.1 %           3       0.0 %  sys_set_object_str
    2.597 us       0.0 %    2.597 us       0.1 %           1       0.0 %  readlink
    2.425 us       0.0 %    2.425 us       0.1 %           1       0.0 %  floor
    2.270 us       0.0 %    2.270 us       0.1 %           1       0.0 %  munmap
    3.527 us       0.1 %    2.119 us       0.1 %           1       0.0 %  Py_GetBuildInfo
    2.096 us       0.0 %    2.096 us       0.1 %           1       0.0 %  confstr
    2.069 us       0.0 %    2.069 us       0.1 %          22       0.0 %  wcscat
    2.480 us       0.0 %    1.914 us       0.0 %           1       0.0 %  _PySys_SetPreliminaryStderr
    1.405 us       0.0 %    1.405 us       0.0 %           6       0.0 %  sys_set_object
    1.384 us       0.0 %    1.384 us       0.0 %           1       0.0 %  __libc_current_sigrtmin
    1.365 us       0.0 %    1.365 us       0.0 %           2       0.0 %  vsnprintf
    2.284 us       0.0 %    1.259 us       0.0 %           1       0.0 %  calculate_module_search_path
    1.251 us       0.0 %    1.251 us       0.0 %           3       0.0 %  dup
    1.036 us       0.0 %    1.036 us       0.0 %           1       0.0 %  fclose
    1.105 us       0.0 %    1.022 us       0.0 %           1       0.0 %  get_hash_info
    0.997 us       0.0 %    0.997 us       0.0 %          15       0.0 %  memmove
    1.638 us       0.0 %    0.966 us       0.0 %           3       0.0 %  joinpath
    2.913 us       0.1 %    0.958 us       0.0 %           9       0.0 %  _PyInterpreterState_GET
  118.785 us       2.2 %    0.923 us       0.0 %           1       0.0 %  calculate_path
    1.057 us       0.0 %    0.899 us       0.0 %           1       0.0 %  make_version_info
    1.943 us       0.0 %    0.898 us       0.0 %           2       0.0 %  sys_getfilesystemencoding_impl
    0.873 us       0.0 %    0.873 us       0.0 %           1       0.0 %  getrandom
    0.842 us       0.0 %    0.842 us       0.0 %           4       0.0 %  sys_get_object_id
    0.833 us       0.0 %    0.833 us       0.0 %           3       0.0 %  fcntl64
    2.546 us       0.0 %    0.831 us       0.0 %           4       0.0 %  _PySys_GetObjectId
    0.701 us       0.0 %    0.701 us       0.0 %           9       0.0 %  wcschr
    0.630 us       0.0 %    0.630 us       0.0 %           1       0.0 %  __libc_current_sigrtmax
    0.617 us       0.0 %    0.617 us       0.0 %           8       0.0 %  fileno
    0.820 us       0.0 %    0.606 us       0.0 %           1       0.0 %  calculate_program_impl
    0.595 us       0.0 %    0.595 us       0.0 %           8       0.0 %  wcscpy
  126.780 us       2.4 %    0.569 us       0.0 %           1       0.0 %  _PyPathConfig_Calculate
    5.832 us       0.1 %    0.537 us       0.0 %           3       0.0 %  PySys_SetObject
   14.805 us       0.3 %    0.532 us       0.0 %           1       0.0 %  calculate_argv0_path
   31.851 us       0.6 %    0.520 us       0.0 %           1       0.0 %  search_for_prefix
    0.770 us       0.0 %    0.513 us       0.0 %           2       0.0 %  safe_wcscpy
    2.982 us       0.1 %    0.485 us       0.0 %           1       0.0 %  make_flags
    5.846 us       0.1 %    0.477 us       0.0 %           3       0.0 %  _PySys_SetObjectId
   24.495 us       0.5 %    0.476 us       0.0 %           1       0.0 %  calculate_exec_prefix
   32.692 us       0.6 %    0.465 us       0.0 %           1       0.0 %  calculate_prefix
    0.835 us       0.0 %    0.445 us       0.0 %           1       0.0 %  sys_getfilesystemencodeerrors_impl
    0.537 us       0.0 %    0.413 us       0.0 %           1       0.0 %  calculate_set_prefix
    0.372 us       0.0 %    0.372 us       0.0 %           4       0.0 %  memchr
    0.926 us       0.0 %    0.369 us       0.0 %           1       0.0 %  _PySys_ClearAuditHooks
    0.368 us       0.0 %    0.368 us       0.0 %           3       0.0 %  wcsncpy
    0.524 us       0.0 %    0.356 us       0.0 %           2       0.0 %  reduce
    0.337 us       0.0 %    0.337 us       0.0 %           4       0.0 %  sigemptyset
    0.597 us       0.0 %    0.332 us       0.0 %           2       0.0 %  _Py_gitidentifier
    0.440 us       0.0 %    0.309 us       0.0 %           1       0.0 %  calculate_set_exec_prefix
    2.246 us       0.0 %    0.303 us       0.0 %           2       0.0 %  sys_getfilesystemencoding
    0.295 us       0.0 %    0.295 us       0.0 %           2       0.0 %  fflush
    0.418 us       0.0 %    0.280 us       0.0 %           1       0.0 %  _PySys_ReadPreinitWarnOptions
    0.247 us       0.0 %    0.247 us       0.0 %           1       0.0 %  geteuid
   27.857 us       0.5 %    0.240 us       0.0 %           2       0.0 %  isfile
    0.238 us       0.0 %    0.238 us       0.0 %           1       0.0 %  calculate_free
    0.220 us       0.0 %    0.220 us       0.0 %           2       0.0 %  _clear_preinit_entries
    0.215 us       0.0 %    0.215 us       0.0 %           1       0.0 %  sysconf
    1.964 us       0.0 %    0.209 us       0.0 %           1       0.0 %  calculate_zip_path
   13.059 us       0.2 %    0.207 us       0.0 %           1       0.0 %  ismodule
    0.204 us       0.0 %    0.204 us       0.0 %           2       0.0 %  pthread_cond_init
    0.183 us       0.0 %    0.183 us       0.0 %           1       0.0 %  pthread_key_delete
    0.170 us       0.0 %    0.170 us       0.0 %           4       0.0 %  _PyErr_Occurred
    0.987 us       0.0 %    0.167 us       0.0 %           1       0.0 %  calculate_program
    0.160 us       0.0 %    0.160 us       0.0 %           2       0.0 %  pthread_mutex_init
    0.155 us       0.0 %    0.155 us       0.0 %           1       0.0 %  syscall
    0.236 us       0.0 %    0.154 us       0.0 %           1       0.0 %  _PySys_ReadPreinitXOptions
    0.151 us       0.0 %    0.151 us       0.0 %           1       0.0 %  getegid
    0.145 us       0.0 %    0.145 us       0.0 %           1       0.0 %  getuid
   23.703 us       0.4 %    0.142 us       0.0 %           1       0.0 %  search_for_exec_prefix
   39.658 us       0.7 %    0.137 us       0.0 %           1       0.0 %  calculate_read_pyenv
    0.132 us       0.0 %    0.132 us       0.0 %           1       0.0 %  sys_create_xoptions_dict
    0.115 us       0.0 %    0.115 us       0.0 %           1       0.0 %  getgid
    0.944 us       0.0 %    0.109 us       0.0 %           1       0.0 %  sys_getfilesystemencodeerrors
    0.103 us       0.0 %    0.103 us       0.0 %           2       0.0 %  nl_langinfo
    0.093 us       0.0 %    0.093 us       0.0 %           1       0.0 %  pthread_key_create
    0.090 us       0.0 %    0.090 us       0.0 %           1       0.0 %  _PyRuntimeState_GetFinalizing
    0.084 us       0.0 %    0.084 us       0.0 %           2       0.0 %  _Py_gitversion
    0.070 us       0.0 %    0.070 us       0.0 %           1       0.0 %  _Py_INCREF
    0.067 us       0.0 %    0.067 us       0.0 %           1       0.0 %  pthread_condattr_init
    0.062 us       0.0 %    0.062 us       0.0 %           1       0.0 %  pthread_setspecific
    0.057 us       0.0 %    0.057 us       0.0 %           1       0.0 %  pthread_getspecific
    0.051 us       0.0 %    0.051 us       0.0 %           1       0.0 %  time
    0.047 us       0.0 %    0.047 us       0.0 %           1       0.0 %  pthread_condattr_setclock

totals:
Total time: 5390.698 us
Self time:  3978.792 us
Calls:      51105

the call graph

# Function Call Graph for 'python' (session: 24d0ada574ddcd32)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME   FUNCTION
    4.118 ms : (1) python
  420.757 us :  +-(5907) memset
             :  |
    0.113 us :  +-(1) pthread_condattr_init
             :  |
    0.121 us :  +-(1) pthread_condattr_setclock
             :  |
    4.099 us :  +-(71) sem_init
             :  |
   24.664 us :  +-(532) pthread_self
             :  |
   25.638 us :  +-(8) setlocale
             :  |
  400.608 us :  +-(6621) strlen
             :  |
  751.204 us :  +-(14312) memcpy
             :  |
    9.706 us :  +-(199) strcmp
             :  |
   77.311 us :  +-(696) mbstowcs
             :  |
   39.396 us :  +-(723) wcscmp
             :  |
    0.694 us :  +-(6) wcschr
             :  |
    4.372 us :  +-(29) getenv
             :  |
    9.458 us :  +-(131) wcslen
             :  |
    0.425 us :  +-(1) _PySys_ReadPreinitWarnOptions
    0.156 us :  | (1) _clear_preinit_entries
             :  |
    0.243 us :  +-(1) _PySys_ReadPreinitXOptions
    0.061 us :  | (1) _clear_preinit_entries
             :  |
    0.129 us :  +-(2) nl_langinfo
             :  |
   76.388 us :  +-(1695) __errno_location
             :  |
    1.006 us :  +-(1) getrandom
             :  |
    0.071 us :  +-(1) pthread_key_create
             :  |
   11.871 us :  +-(28) _PySys_Audit
    8.673 us :  | (28) sys_audit_tstate
    5.729 us :  | (27) should_audit
    1.083 us :  | (27) PyDTrace_AUDIT_ENABLED
             :  |
   38.755 us :  +-(8) calloc
             :  |
    7.351 us :  +-(116) sem_wait
             :  |
   19.426 us :  +-(336) sem_post
             :  |
    0.165 us :  +-(1) syscall
             :  |
    4.537 us :  +-(3) mmap64
             :  |
    0.072 us :  +-(1) pthread_getspecific
             :  |
    0.049 us :  +-(1) pthread_setspecific
             :  |
    0.187 us :  +-(2) pthread_mutex_init
             :  |
    0.154 us :  +-(2) pthread_cond_init
             :  |
   87.596 us :  +-(1790) pthread_mutex_lock
             :  |
   59.446 us :  +-(1193) pthread_cond_signal
             :  |
   84.008 us :  +-(1790) pthread_mutex_unlock
             :  |
   25.914 us :  +-(113) realloc
             :  |
  293.147 us :  +-(6098) memcmp
             :  |
   13.611 us :  +-(216) strrchr
             :  |
   13.879 us :  +-(228) strncmp
             :  |
  488.586 us :  +-(1) _PySys_Create
    3.144 us :  |  +-(46) strlen
             :  |  |
    0.237 us :  |  +-(5) sem_wait
             :  |  |
    0.274 us :  |  +-(5) sem_post
             :  |  |
    0.124 us :  |  +-(2) memcmp
             :  |  |
    0.953 us :  |  +-(14) memset
             :  |  |
    2.356 us :  |  +-(41) memcpy
             :  |  |
    0.081 us :  |  +-(1) _Py_INCREF
             :  |  |
    2.636 us :  |  +-(1) _PySys_SetPreliminaryStderr
    0.233 us :  |  |  +-(3) fileno
             :  |  |  |
    0.054 us :  |  |  +-(1) sem_wait
             :  |  |  |
    0.055 us :  |  |  +-(1) sem_post
             :  |  |  |
    0.165 us :  |  |  +-(2) strlen
             :  |  |  |
    0.051 us :  |  |  +-(1) memcpy
             :  |  |  |
    0.060 us :  |  |  +-(1) _Py_DECREF
             :  |  |
  372.437 us :  |  +-(1) _PySys_InitCore
    8.487 us :  |     +-(155) strlen
             :  |     |
    5.906 us :  |     +-(105) memcpy
             :  |     |
    2.121 us :  |     +-(37) memcmp
             :  |     |
    1.266 us :  |     +-(28) _Py_DECREF
             :  |     |
    2.247 us :  |     +-(1) Py_GetBuildInfo
    0.044 us :  |     |  +-(1) _Py_gitversion
             :  |     |  |
    0.330 us :  |     |  +-(1) _Py_gitidentifier
    0.141 us :  |     |  | (1) strcmp
             :  |     |  |
    1.333 us :  |     |  +-(1) vsnprintf
             :  |     |
    0.499 us :  |     +-(1) vsnprintf
             :  |     |
    0.037 us :  |     +-(1) _Py_gitversion
             :  |     |
    0.203 us :  |     +-(1) _Py_gitidentifier
    0.055 us :  |     | (1) strcmp
             :  |     |
    4.160 us :  |     +-(77) memset
             :  |     |
    0.356 us :  |     +-(5) strrchr
             :  |     |
    0.345 us :  |     +-(5) strncmp
             :  |     |
    1.276 us :  |     +-(1) get_hash_info
    0.046 us :  |     |  +-(1) strlen
             :  |     |  |
    0.048 us :  |     |  +-(1) _PyErr_Occurred
             :  |     |
   43.117 us :  |     +-(1) list_builtin_module_names
    1.496 us :  |     |  +-(30) strlen
             :  |     |  |
    1.701 us :  |     |  +-(32) memcpy
             :  |     |  |
    2.122 us :  |     |  +-(31) _Py_DECREF
             :  |     |  |
    4.868 us :  |     |  +-(110) memcmp
             :  |     |
  165.611 us :  |     +-(1) list_stdlib_module_names
   15.687 us :  |     |  +-(303) strlen
             :  |     |  |
   13.682 us :  |     |  +-(269) memcpy
             :  |     |  |
    1.364 us :  |     |  +-(4) memset
             :  |     |  |
    2.414 us :  |     |  +-(1) _Py_DECREF
             :  |     |
    0.987 us :  |     +-(1) make_version_info
    0.052 us :  |     |  +-(1) strlen
             :  |     |  |
    0.054 us :  |     |  +-(1) memcpy
             :  |     |  |
    0.047 us :  |     |  +-(1) _PyErr_Occurred
             :  |     |
    7.756 us :  |     +-(1) make_impl_info
    0.425 us :  |     |  +-(8) strlen
             :  |     |  |
    0.369 us :  |     |  +-(7) memcpy
             :  |     |  |
    0.174 us :  |     |  +-(3) memcmp
             :  |     |  |
    0.181 us :  |     |  +-(3) memset
             :  |     |  |
    0.585 us :  |     |  +-(5) _Py_DECREF
             :  |     |
    2.923 us :  |     +-(1) make_flags
    2.519 us :  |     | (1) set_flags_from_config
    0.631 us :  |     | (16) _Py_XDECREF
             :  |     |
    2.286 us :  |     +-(1) confstr
             :  |     |
    0.288 us :  |     +-(2) wcscmp
             :  |     |
    0.656 us :  |     +-(2) mbstowcs
             :  |     |
    0.037 us :  |     +-(1) _PyErr_Occurred
             :  |
   39.689 us :  +-(55) PySys_Audit
   12.526 us :  |  +-(55) _PyThreadState_GET
    3.107 us :  |  | (55) _PyRuntimeState_GetThreadState
             :  |  |
   16.585 us :  |  +-(55) sys_audit_tstate
   10.618 us :  |    (55) should_audit
    2.298 us :  |    (55) PyDTrace_AUDIT_ENABLED
             :  |
   23.228 us :  +-(325) strchr
             :  |
    3.773 us :  +-(46) memrchr
             :  |
    2.692 us :  +-(1) floor
             :  |
  173.480 us :  +-(1) _PyPathConfig_Calculate
    0.093 us :  |  +-(1) memset
             :  |  |
   11.254 us :  |  +-(1) calculate_init
    2.333 us :  |  |  +-(1) getenv
             :  |  |  |
    2.260 us :  |  |  +-(12) mbstowcs
             :  |  |  |
    3.303 us :  |  |  +-(1) joinpath2
    0.157 us :  |  |     +-(2) wcslen
             :  |  |     |
    2.003 us :  |  |     +-(1) wcscpy
             :  |  |     |
    0.305 us :  |  |     +-(2) wcscat
             :  |  |
  161.149 us :  |  +-(1) calculate_path
    1.107 us :  |  |  +-(1) calculate_program
    0.920 us :  |  |  | (1) calculate_program_impl
    0.114 us :  |  |  |  +-(1) wcschr
             :  |  |  |  |
    0.087 us :  |  |  |  +-(1) wcslen
             :  |  |  |  |
    0.073 us :  |  |  |  +-(1) memcpy
             :  |  |  |
   15.093 us :  |  |  +-(1) calculate_argv0_path
    0.080 us :  |  |  |  +-(1) wcslen
             :  |  |  |  |
    0.065 us :  |  |  |  +-(1) memcpy
             :  |  |  |  |
   14.166 us :  |  |  |  +-(1) resolve_symlinks
    0.081 us :  |  |  |  |  +-(1) wcslen
             :  |  |  |  |  |
    4.716 us :  |  |  |  |  +-(72) wcstombs
             :  |  |  |  |  |
    2.830 us :  |  |  |  |  +-(1) readlink
             :  |  |  |  |
    0.289 us :  |  |  |  +-(1) reduce
    0.084 us :  |  |  |    (1) wcslen
             :  |  |  |
   41.001 us :  |  |  +-(1) calculate_read_pyenv
   40.854 us :  |  |  | (1) calculate_open_pyenv
    1.991 us :  |  |  |  +-(2) joinpath2
    0.254 us :  |  |  |  |  +-(4) wcslen
             :  |  |  |  |  |
    0.131 us :  |  |  |  |  +-(2) wcscpy
             :  |  |  |  |  |
    0.358 us :  |  |  |  |  +-(4) wcscat
             :  |  |  |  |
    1.429 us :  |  |  |  +-(2) PySys_Audit
    0.419 us :  |  |  |  |  +-(2) _PyThreadState_GET
    0.115 us :  |  |  |  |  | (2) _PyRuntimeState_GetThreadState
             :  |  |  |  |  |
    0.574 us :  |  |  |  |  +-(2) sys_audit_tstate
    0.358 us :  |  |  |  |    (2) should_audit
    0.083 us :  |  |  |  |    (2) PyDTrace_AUDIT_ENABLED
             :  |  |  |  |
    9.118 us :  |  |  |  +-(146) wcstombs
             :  |  |  |  |
    0.197 us :  |  |  |  +-(3) wcslen
             :  |  |  |  |
    4.756 us :  |  |  |  +-(2) fopen64
             :  |  |  |  |
    0.132 us :  |  |  |  +-(2) __errno_location
             :  |  |  |  |
    0.064 us :  |  |  |  +-(1) memcpy
             :  |  |  |  |
    0.259 us :  |  |  |  +-(1) reduce
    0.073 us :  |  |  |    (1) wcslen
             :  |  |  |
   55.537 us :  |  |  +-(1) calculate_prefix
    0.366 us :  |  |  |  +-(1) memset
             :  |  |  |  |
   54.338 us :  |  |  |  +-(1) search_for_prefix
    1.454 us :  |  |  |  |  +-(1) joinpath2
    0.234 us :  |  |  |  |  |  +-(2) wcslen
             :  |  |  |  |  |  |
    0.093 us :  |  |  |  |  |  +-(1) wcscpy
             :  |  |  |  |  |  |
    0.227 us :  |  |  |  |  |  +-(2) wcscat
             :  |  |  |  |  |
   26.472 us :  |  |  |  |  +-(1) isfile
   26.280 us :  |  |  |  |  | (1) _Py_wstat
    0.094 us :  |  |  |  |  |  +-(1) wcslen
             :  |  |  |  |  |  |
    9.612 us :  |  |  |  |  |  +-(98) wcstombs
             :  |  |  |  |  |  |
    2.341 us :  |  |  |  |  |  +-(1) __xstat64
             :  |  |  |  |  |
    0.588 us :  |  |  |  |  +-(1) safe_wcscpy
    0.090 us :  |  |  |  |  |  +-(1) wcslen
             :  |  |  |  |  |  |
    0.074 us :  |  |  |  |  |  +-(1) memcpy
             :  |  |  |  |  |
    1.856 us :  |  |  |  |  +-(2) joinpath
    0.341 us :  |  |  |  |  |  +-(4) wcslen
             :  |  |  |  |  |  |
    0.299 us :  |  |  |  |  |  +-(2) wcsncpy
             :  |  |  |  |  |
   23.209 us :  |  |  |  |  +-(1) ismodule
    1.500 us :  |  |  |  |     +-(1) joinpath2
    0.186 us :  |  |  |  |     |  +-(2) wcslen
             :  |  |  |  |     |  |
    0.098 us :  |  |  |  |     |  +-(1) wcscpy
             :  |  |  |  |     |  |
    0.241 us :  |  |  |  |     |  +-(2) wcscat
             :  |  |  |  |     |
   21.379 us :  |  |  |  |     +-(1) isfile
   21.225 us :  |  |  |  |       (1) _Py_wstat
    0.061 us :  |  |  |  |        +-(1) wcslen
             :  |  |  |  |        |
    8.351 us :  |  |  |  |        +-(78) wcstombs
             :  |  |  |  |        |
    1.439 us :  |  |  |  |        +-(1) __xstat64
             :  |  |  |  |
    0.075 us :  |  |  |  +-(1) wcslen
             :  |  |  |  |
    0.086 us :  |  |  |  +-(1) memcpy
             :  |  |  |
    2.892 us :  |  |  +-(1) calculate_zip_path
    2.567 us :  |  |  | (2) joinpath2
    0.312 us :  |  |  |  +-(4) wcslen
             :  |  |  |  |
    0.216 us :  |  |  |  +-(2) wcscpy
             :  |  |  |  |
    0.464 us :  |  |  |  +-(4) wcscat
             :  |  |  |
   39.449 us :  |  |  +-(1) calculate_exec_prefix
    0.482 us :  |  |  |  +-(1) memset
             :  |  |  |  |
   38.194 us :  |  |  |  +-(1) search_for_exec_prefix
   37.980 us :  |  |  |  | (1) calculate_pybuilddir
    1.441 us :  |  |  |  |  +-(1) joinpath2
    0.187 us :  |  |  |  |  |  +-(2) wcslen
             :  |  |  |  |  |  |
    0.096 us :  |  |  |  |  |  +-(1) wcscpy
             :  |  |  |  |  |  |
    0.259 us :  |  |  |  |  |  +-(2) wcscat
             :  |  |  |  |  |
    0.949 us :  |  |  |  |  +-(1) PySys_Audit
    0.237 us :  |  |  |  |  |  +-(1) _PyThreadState_GET
    0.044 us :  |  |  |  |  |  | (1) _PyRuntimeState_GetThreadState
             :  |  |  |  |  |  |
    0.453 us :  |  |  |  |  |  +-(1) sys_audit_tstate
    0.278 us :  |  |  |  |  |    (1) should_audit
    0.061 us :  |  |  |  |  |    (1) PyDTrace_AUDIT_ENABLED
             :  |  |  |  |  |
    9.561 us :  |  |  |  |  +-(89) wcstombs
             :  |  |  |  |  |
    0.090 us :  |  |  |  |  +-(1) wcslen
             :  |  |  |  |  |
    2.675 us :  |  |  |  |  +-(1) fopen64
             :  |  |  |  |  |
    0.124 us :  |  |  |  |  +-(1) fileno
             :  |  |  |  |  |
    0.661 us :  |  |  |  |  +-(2) fcntl64
             :  |  |  |  |  |
    4.528 us :  |  |  |  |  +-(1) fread
             :  |  |  |  |  |
    1.591 us :  |  |  |  |  +-(1) fclose
             :  |  |  |  |  |
    0.564 us :  |  |  |  |  +-(1) safe_wcscpy
    0.087 us :  |  |  |  |  |  +-(1) wcslen
             :  |  |  |  |  |  |
    0.081 us :  |  |  |  |  |  +-(1) memcpy
             :  |  |  |  |  |
    0.927 us :  |  |  |  |  +-(1) joinpath
    0.178 us :  |  |  |  |     +-(2) wcslen
             :  |  |  |  |     |
    0.185 us :  |  |  |  |     +-(1) wcsncpy
             :  |  |  |  |
    0.067 us :  |  |  |  +-(1) wcslen
             :  |  |  |  |
    0.073 us :  |  |  |  +-(1) memcpy
             :  |  |  |
    3.365 us :  |  |  +-(1) calculate_module_search_path
    0.403 us :  |  |  |  +-(4) wcslen
             :  |  |  |  |
    0.191 us :  |  |  |  +-(2) wcschr
             :  |  |  |  |
    0.748 us :  |  |  |  +-(6) wcscat
             :  |  |  |
    0.816 us :  |  |  +-(1) calculate_set_prefix
    0.100 us :  |  |  |  +-(1) wcslen
             :  |  |  |  |
    0.098 us :  |  |  |  +-(1) memcpy
             :  |  |  |
    0.743 us :  |  |  +-(1) calculate_set_exec_prefix
    0.142 us :  |  |     +-(1) wcslen
             :  |  |     |
    0.082 us :  |  |     +-(1) memcpy
             :  |  |
    0.347 us :  |  +-(1) calculate_free
             :  |
   30.970 us :  +-(1) _PySys_UpdateConfig
    0.464 us :  |  +-(5) memset
             :  |  |
    1.021 us :  |  +-(14) wcslen
             :  |  |
    0.899 us :  |  +-(14) strlen
             :  |  |
    0.873 us :  |  +-(15) memcpy
             :  |  |
    0.150 us :  |  +-(2) memcmp
             :  |  |
    0.545 us :  |  +-(13) _Py_DECREF
             :  |  |
    0.138 us :  |  +-(1) sys_create_xoptions_dict
             :  |  |
    1.026 us :  |  +-(1) _PySys_GetObject
    0.074 us :  |  |  +-(1) strlen
             :  |  |  |
    0.056 us :  |  |  +-(1) memcpy
             :  |  |  |
    0.069 us :  |  |  +-(1) memcmp
             :  |  |
    4.197 us :  |  +-(1) set_flags_from_config
    2.554 us :  |  | (16) _Py_XDECREF
    0.597 us :  |  | (16) _Py_DECREF
             :  |  |
    0.036 us :  |  +-(1) _PyErr_Occurred
             :  |
   99.010 us :  +-(77) PySys_GetObject
   14.570 us :  |  +-(77) _PyThreadState_GET
    3.687 us :  |  | (77) _PyRuntimeState_GetThreadState
             :  |  |
   69.927 us :  |  +-(77) _PySys_GetObject
    5.291 us :  |     +-(77) strlen
             :  |     |
    4.631 us :  |     +-(77) memcpy
             :  |     |
    4.791 us :  |     +-(77) memcmp
             :  |
   12.714 us :  +-(220) sem_trywait
             :  |
    3.883 us :  +-(71) sem_destroy
             :  |
   81.231 us :  +-(3) qsort
   24.086 us :  | (567) strcmp
             :  |
    0.226 us :  +-(1) sysconf
             :  |
   10.721 us :  +-(110) strncpy
             :  |
    0.444 us :  +-(4) memchr
             :  |
    0.053 us :  +-(1) time
             :  |
   14.679 us :  +-(2) localtime_r
             :  |
  184.218 us :  +-(2958) wcstombs
             :  |
   83.332 us :  +-(61) __xstat64
             :  |
    6.392 us :  +-(14) strerror
             :  |
   14.368 us :  +-(3) opendir
             :  |
  139.292 us :  +-(413) readdir64
             :  |
   21.294 us :  +-(3) closedir
             :  |
   38.411 us :  +-(13) open64
             :  |
    0.382 us :  +-(1) fcntl64
             :  |
    9.947 us :  +-(30) __fxstat64
             :  |
    8.927 us :  +-(19) isatty
             :  |
    6.047 us :  +-(29) lseek64
             :  |
   60.254 us :  +-(26) read
             :  |
   14.366 us :  +-(16) close
             :  |
    0.357 us :  +-(4) sigemptyset
             :  |
   10.233 us :  +-(68) sigaction
             :  |
    2.021 us :  +-(1) __libc_current_sigrtmin
             :  |
    0.640 us :  +-(1) __libc_current_sigrtmax
             :  |
    0.411 us :  +-(4) fileno
             :  |
    1.456 us :  +-(3) dup
             :  |
    6.718 us :  +-(3) PySys_SetObject
    0.990 us :  |  +-(3) _PyInterpreterState_GET
    0.667 us :  |  | (3) _PyThreadState_GET
    0.160 us :  |  | (3) _PyRuntimeState_GetThreadState
             :  |  |
    5.184 us :  |  +-(3) sys_set_object_str
    0.189 us :  |     +-(3) strlen
             :  |     |
    1.049 us :  |     +-(3) sys_set_object
             :  |     |
    0.565 us :  |     +-(3) _Py_XDECREF
    0.143 us :  |     | (3) _Py_DECREF
             :  |     |
    0.134 us :  |     +-(2) memcpy
             :  |     |
    0.070 us :  |     +-(1) memcmp
             :  |
    5.697 us :  +-(3) _PySys_SetObjectId
    0.856 us :  |  +-(3) _PyInterpreterState_GET
    0.556 us :  |  | (3) _PyThreadState_GET
    0.128 us :  |  | (3) _PyRuntimeState_GetThreadState
             :  |  |
    4.370 us :  |  +-(3) sys_set_object_id
    0.239 us :  |     +-(3) sem_wait
             :  |     |
    0.179 us :  |     +-(3) sem_post
             :  |     |
    0.155 us :  |     +-(3) strlen
             :  |     |
    0.116 us :  |     +-(2) memcpy
             :  |     |
    0.496 us :  |     +-(3) sys_set_object
             :  |     |
    0.064 us :  |     +-(1) memcmp
             :  |
    0.994 us :  +-(15) memmove
             :  |
    2.328 us :  +-(2) sys_getfilesystemencoding
    2.004 us :  | (2) sys_getfilesystemencoding_impl
    0.752 us :  |  +-(2) _PyInterpreterState_GET
    0.548 us :  |  | (2) _PyThreadState_GET
    0.111 us :  |  | (2) _PyRuntimeState_GetThreadState
             :  |  |
    0.259 us :  |  +-(2) wcslen
             :  |
    1.011 us :  +-(1) sys_getfilesystemencodeerrors
    0.896 us :  | (1) sys_getfilesystemencodeerrors_impl
    0.311 us :  |  +-(1) _PyInterpreterState_GET
    0.220 us :  |  | (1) _PyThreadState_GET
    0.040 us :  |  | (1) _PyRuntimeState_GetThreadState
             :  |  |
    0.101 us :  |  +-(1) wcslen
             :  |
    0.343 us :  +-(1) geteuid
             :  |
    0.238 us :  +-(1) getuid
             :  |
    0.164 us :  +-(1) getegid
             :  |
    0.121 us :  +-(1) getgid
             :  |
    2.355 us :  +-(4) _PySys_GetObjectId
    0.895 us :  |  +-(4) _PyThreadState_GET
    0.216 us :  |  | (4) _PyRuntimeState_GetThreadState
             :  |  |
    0.664 us :  |  +-(4) sys_get_object_id
             :  |
    0.935 us :  +-(1) _PySys_ClearAuditHooks
    0.084 us :  |  +-(1) _PyRuntimeState_GetFinalizing
             :  |  |
    0.483 us :  |  +-(1) _PySys_Audit
    0.364 us :  |    (1) sys_audit_tstate
    0.247 us :  |    (1) should_audit
    0.050 us :  |    (1) PyDTrace_AUDIT_ENABLED
             :  |
    0.202 us :  +-(1) pthread_key_delete
             :  |
    2.413 us :  +-(1) munmap
             :  |
    0.347 us :  +-(2) fflush

(with percentages and totals)

# Function Call Graph for 'python' (session: f03290c62782639b)
# (total run time: 9368.698 us)
========== FUNCTION CALL GRAPH ==========
# RUNNING %  TOTAL %  TOTAL TIME   FUNCTION
     42.5 %   42.5 %    3.978 ms : (1) python
     46.8 %    4.4 %  408.654 us :  +-(5907) memset
                                 :  |
     46.8 %    0.0 %    0.067 us :  +-(1) pthread_condattr_init
                                 :  |
     46.8 %    0.0 %    0.047 us :  +-(1) pthread_condattr_setclock
                                 :  |
     46.9 %    0.0 %    4.133 us :  +-(71) sem_init
                                 :  |
     47.1 %    0.3 %   24.050 us :  +-(532) pthread_self
                                 :  |
     47.4 %    0.2 %   21.619 us :  +-(8) setlocale
                                 :  |
     51.4 %    4.1 %  382.536 us :  +-(6621) strlen
                                 :  |
     59.4 %    8.0 %  745.132 us :  +-(14312) memcpy
                                 :  |
     59.5 %    0.1 %   10.749 us :  +-(199) strcmp
                                 :  |
     60.3 %    0.8 %   71.453 us :  +-(696) mbstowcs
                                 :  |
     60.7 %    0.4 %   37.705 us :  +-(723) wcscmp
                                 :  |
     60.7 %    0.0 %    0.472 us :  +-(6) wcschr
                                 :  |
     60.7 %    0.0 %    4.101 us :  +-(29) getenv
                                 :  |
     60.8 %    0.1 %    8.939 us :  +-(131) wcslen
                                 :  |
     60.8 %    0.0 %    0.418 us :  +-(1) _PySys_ReadPreinitWarnOptions
     60.8 %    0.0 %    0.138 us :  | (1) _clear_preinit_entries
                                 :  |
     60.8 %    0.0 %    0.236 us :  +-(1) _PySys_ReadPreinitXOptions
     60.8 %    0.0 %    0.082 us :  | (1) _clear_preinit_entries
                                 :  |
     60.8 %    0.0 %    0.103 us :  +-(2) nl_langinfo
                                 :  |
     61.6 %    0.8 %   74.672 us :  +-(1695) __errno_location
                                 :  |
     61.6 %    0.0 %    0.873 us :  +-(1) getrandom
                                 :  |
     61.6 %    0.0 %    0.093 us :  +-(1) pthread_key_create
                                 :  |
     61.8 %    0.1 %   11.813 us :  +-(28) _PySys_Audit
     61.9 %    0.1 %    8.727 us :  | (28) sys_audit_tstate
     61.9 %    0.1 %    5.742 us :  | (27) should_audit
     61.9 %    0.0 %    1.074 us :  | (27) PyDTrace_AUDIT_ENABLED
                                 :  |
     62.4 %    0.4 %   40.796 us :  +-(8) calloc
                                 :  |
     62.4 %    0.1 %    6.931 us :  +-(116) sem_wait
                                 :  |
     62.6 %    0.2 %   19.704 us :  +-(336) sem_post
                                 :  |
     62.6 %    0.0 %    0.155 us :  +-(1) syscall                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     [388/19148]
                                 :  |
     62.7 %    0.0 %    3.665 us :  +-(3) mmap64
                                 :  |
     62.7 %    0.0 %    0.057 us :  +-(1) pthread_getspecific
                                 :  |
     62.7 %    0.0 %    0.062 us :  +-(1) pthread_setspecific
                                 :  |
     62.7 %    0.0 %    0.160 us :  +-(2) pthread_mutex_init
                                 :  |
     62.7 %    0.0 %    0.204 us :  +-(2) pthread_cond_init
                                 :  |
     63.6 %    0.9 %   84.888 us :  +-(1790) pthread_mutex_lock
                                 :  |
     64.2 %    0.6 %   58.134 us :  +-(1193) pthread_cond_signal
                                 :  |
     65.1 %    0.9 %   82.172 us :  +-(1790) pthread_mutex_unlock
                                 :  |
     65.4 %    0.3 %   26.700 us :  +-(113) realloc
                                 :  |
     68.5 %    3.1 %  293.092 us :  +-(6098) memcmp
                                 :  |
     68.6 %    0.1 %   12.416 us :  +-(216) strrchr
                                 :  |
     68.8 %    0.1 %   13.317 us :  +-(228) strncmp
                                 :  |
     73.9 %    5.2 %  482.818 us :  +-(1) _PySys_Create
     74.0 %    0.0 %    3.179 us :  |  +-(46) strlen
                                 :  |  |
     74.0 %    0.0 %    0.230 us :  |  +-(5) sem_wait
                                 :  |  |
     74.0 %    0.0 %    0.266 us :  |  +-(5) sem_post
                                 :  |  |
     74.0 %    0.0 %    0.121 us :  |  +-(2) memcmp
                                 :  |  |
     74.0 %    0.0 %    0.930 us :  |  +-(14) memset
                                 :  |  |
     74.0 %    0.0 %    2.296 us :  |  +-(41) memcpy
                                 :  |  |
     74.0 %    0.0 %    0.070 us :  |  +-(1) _Py_INCREF
                                 :  |  |
     74.0 %    0.0 %    2.480 us :  |  +-(1) _PySys_SetPreliminaryStderr
     74.0 %    0.0 %    0.197 us :  |  |  +-(3) fileno
                                 :  |  |  |
     74.0 %    0.0 %    0.042 us :  |  |  +-(1) sem_wait
                                 :  |  |  |
     74.0 %    0.0 %    0.061 us :  |  |  +-(1) sem_post
                                 :  |  |  |
     74.0 %    0.0 %    0.147 us :  |  |  +-(2) strlen
                                 :  |  |  |
     74.0 %    0.0 %    0.053 us :  |  |  +-(1) memcpy
                                 :  |  |  |
     74.0 %    0.0 %    0.066 us :  |  |  +-(1) _Py_DECREF
                                 :  |  |
     78.0 %    3.9 %  368.594 us :  |  +-(1) _PySys_InitCore
     78.1 %    0.1 %    8.168 us :  |     +-(155) strlen
                                 :  |     |
     78.1 %    0.1 %    5.567 us :  |     +-(105) memcpy
                                 :  |     |
     78.1 %    0.0 %    2.057 us :  |     +-(37) memcmp
                                 :  |     |
     78.2 %    0.0 %    1.280 us :  |     +-(28) _Py_DECREF
                                 :  |     |
     78.2 %    0.0 %    3.527 us :  |     +-(1) Py_GetBuildInfo
     78.2 %    0.0 %    0.043 us :  |     |  +-(1) _Py_gitversion
                                 :  |     |  |
     78.2 %    0.0 %    0.394 us :  |     |  +-(1) _Py_gitidentifier
     78.2 %    0.0 %    0.210 us :  |     |  | (1) strcmp
                                 :  |     |  |
     78.2 %    0.0 %    0.971 us :  |     |  +-(1) vsnprintf
                                 :  |     |
     78.2 %    0.0 %    0.394 us :  |     +-(1) vsnprintf
                                 :  |     |
     78.2 %    0.0 %    0.041 us :  |     +-(1) _Py_gitversion
                                 :  |     |
     78.2 %    0.0 %    0.203 us :  |     +-(1) _Py_gitidentifier
     78.2 %    0.0 %    0.055 us :  |     | (1) strcmp
                                 :  |     |
     78.3 %    0.0 %    4.302 us :  |     +-(77) memset
                                 :  |     |
     78.3 %    0.0 %    0.279 us :  |     +-(5) strrchr
                                 :  |     |
     78.3 %    0.0 %    0.365 us :  |     +-(5) strncmp
                                 :  |     |
     78.3 %    0.0 %    1.105 us :  |     +-(1) get_hash_info
     78.3 %    0.0 %    0.041 us :  |     |  +-(1) strlen
                                 :  |     |  |
     78.3 %    0.0 %    0.042 us :  |     |  +-(1) _PyErr_Occurred
                                 :  |     |
     78.7 %    0.4 %   40.290 us :  |     +-(1) list_builtin_module_names
     78.7 %    0.0 %    1.445 us :  |     |  +-(30) strlen
                                 :  |     |  |
     78.8 %    0.0 %    1.672 us :  |     |  +-(32) memcpy
                                 :  |     |  |
     78.8 %    0.0 %    1.977 us :  |     |  +-(31) _Py_DECREF
                                 :  |     |  |
     78.8 %    0.1 %    4.947 us :  |     |  +-(110) memcmp
                                 :  |     |
     80.5 %    1.7 %  159.312 us :  |     +-(1) list_stdlib_module_names
     80.7 %    0.2 %   14.384 us :  |     |  +-(303) strlen
                                 :  |     |  |
     80.8 %    0.1 %   13.259 us :  |     |  +-(269) memcpy
                                 :  |     |  |
     80.8 %    0.0 %    1.452 us :  |     |  +-(4) memset
                                 :  |     |  |
     80.9 %    0.0 %    1.831 us :  |     |  +-(1) _Py_DECREF
                                 :  |     |
     80.9 %    0.0 %    1.057 us :  |     +-(1) make_version_info
     80.9 %    0.0 %    0.056 us :  |     |  +-(1) strlen
                                 :  |     |  |
     80.9 %    0.0 %    0.056 us :  |     |  +-(1) memcpy
                                 :  |     |  |
     80.9 %    0.0 %    0.046 us :  |     |  +-(1) _PyErr_Occurred
                                 :  |     |
     81.0 %    0.1 %    7.582 us :  |     +-(1) make_impl_info
     81.0 %    0.0 %    0.448 us :  |     |  +-(8) strlen
                                 :  |     |  |
     81.0 %    0.0 %    0.367 us :  |     |  +-(7) memcpy
                                 :  |     |  |
     81.0 %    0.0 %    0.182 us :  |     |  +-(3) memcmp
                                 :  |     |  |
     81.0 %    0.0 %    0.178 us :  |     |  +-(3) memset
                                 :  |     |  |
     81.0 %    0.0 %    0.506 us :  |     |  +-(5) _Py_DECREF
                                 :  |     |
     81.0 %    0.0 %    2.982 us :  |     +-(1) make_flags
     81.0 %    0.0 %    2.497 us :  |     | (1) set_flags_from_config
     81.0 %    0.0 %    0.627 us :  |     | (16) _Py_XDECREF
                                 :  |     |
     81.1 %    0.0 %    2.096 us :  |     +-(1) confstr
                                 :  |     |
     81.1 %    0.0 %    0.357 us :  |     +-(2) wcscmp
                                 :  |     |                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           [256/19148]
     81.1 %    0.0 %    0.555 us :  |     +-(2) mbstowcs
                                 :  |     |
     81.1 %    0.0 %    0.043 us :  |     +-(1) _PyErr_Occurred
                                 :  |
     81.5 %    0.4 %   41.060 us :  +-(55) PySys_Audit
     81.7 %    0.1 %   13.767 us :  |  +-(55) _PyThreadState_GET
     81.7 %    0.0 %    3.531 us :  |  | (55) _PyRuntimeState_GetThreadState
                                 :  |  |
     81.9 %    0.2 %   16.980 us :  |  +-(55) sys_audit_tstate
     82.0 %    0.1 %   10.953 us :  |    (55) should_audit
     82.0 %    0.0 %    2.381 us :  |    (55) PyDTrace_AUDIT_ENABLED
                                 :  |
     82.2 %    0.2 %   21.811 us :  +-(325) strchr
                                 :  |
     82.3 %    0.0 %    3.745 us :  +-(46) memrchr
                                 :  |
     82.3 %    0.0 %    2.425 us :  +-(1) floor
                                 :  |
     83.7 %    1.4 %  126.780 us :  +-(1) _PyPathConfig_Calculate
     83.7 %    0.0 %    0.080 us :  |  +-(1) memset
                                 :  |  |
     83.7 %    0.1 %    7.108 us :  |  +-(1) calculate_init
     83.7 %    0.0 %    0.427 us :  |  |  +-(1) getenv
                                 :  |  |  |
     83.8 %    0.0 %    2.094 us :  |  |  +-(12) mbstowcs
                                 :  |  |  |
     83.8 %    0.0 %    1.383 us :  |  |  +-(1) joinpath2
     83.8 %    0.0 %    0.145 us :  |  |     +-(2) wcslen
                                 :  |  |     |
     83.8 %    0.0 %    0.126 us :  |  |     +-(1) wcscpy
                                 :  |  |     |
     83.8 %    0.0 %    0.284 us :  |  |     +-(2) wcscat
                                 :  |  |
     85.1 %    1.3 %  118.785 us :  |  +-(1) calculate_path
     85.1 %    0.0 %    0.987 us :  |  |  +-(1) calculate_program
     85.1 %    0.0 %    0.820 us :  |  |  | (1) calculate_program_impl
     85.1 %    0.0 %    0.083 us :  |  |  |  +-(1) wcschr
                                 :  |  |  |  |
     85.1 %    0.0 %    0.066 us :  |  |  |  +-(1) wcslen
                                 :  |  |  |  |
     85.1 %    0.0 %    0.065 us :  |  |  |  +-(1) memcpy
                                 :  |  |  |
     85.2 %    0.2 %   14.805 us :  |  |  +-(1) calculate_argv0_path
     85.2 %    0.0 %    0.094 us :  |  |  |  +-(1) wcslen
                                 :  |  |  |  |
     85.2 %    0.0 %    0.053 us :  |  |  |  +-(1) memcpy
                                 :  |  |  |  |
     85.4 %    0.1 %   13.841 us :  |  |  |  +-(1) resolve_symlinks
     85.4 %    0.0 %    0.079 us :  |  |  |  |  +-(1) wcslen
                                 :  |  |  |  |  |
     85.4 %    0.1 %    4.722 us :  |  |  |  |  +-(72) wcstombs
                                 :  |  |  |  |  |
     85.5 %    0.0 %    2.597 us :  |  |  |  |  +-(1) readlink
                                 :  |  |  |  |
     85.5 %    0.0 %    0.285 us :  |  |  |  +-(1) reduce
     85.5 %    0.0 %    0.095 us :  |  |  |    (1) wcslen
                                 :  |  |  |
     85.9 %    0.4 %   39.658 us :  |  |  +-(1) calculate_read_pyenv
     86.3 %    0.4 %   39.521 us :  |  |  | (1) calculate_open_pyenv
     86.3 %    0.0 %    2.046 us :  |  |  |  +-(2) joinpath2
     86.3 %    0.0 %    0.261 us :  |  |  |  |  +-(4) wcslen
                                 :  |  |  |  |  |
     86.3 %    0.0 %    0.126 us :  |  |  |  |  +-(2) wcscpy
                                 :  |  |  |  |  |
     86.3 %    0.0 %    0.346 us :  |  |  |  |  +-(4) wcscat
                                 :  |  |  |  |
     86.4 %    0.0 %    1.410 us :  |  |  |  +-(2) PySys_Audit
     86.4 %    0.0 %    0.396 us :  |  |  |  |  +-(2) _PyThreadState_GET
     86.4 %    0.0 %    0.102 us :  |  |  |  |  | (2) _PyRuntimeState_GetThreadState
                                 :  |  |  |  |  |
     86.4 %    0.0 %    0.632 us :  |  |  |  |  +-(2) sys_audit_tstate
     86.4 %    0.0 %    0.388 us :  |  |  |  |    (2) should_audit
     86.4 %    0.0 %    0.081 us :  |  |  |  |    (2) PyDTrace_AUDIT_ENABLED
                                 :  |  |  |  |
     86.5 %    0.1 %    8.977 us :  |  |  |  +-(146) wcstombs
                                 :  |  |  |  |
     86.5 %    0.0 %    0.173 us :  |  |  |  +-(3) wcslen
                                 :  |  |  |  |
     86.5 %    0.0 %    4.488 us :  |  |  |  +-(2) fopen64
                                 :  |  |  |  |
     86.5 %    0.0 %    0.119 us :  |  |  |  +-(2) __errno_location
                                 :  |  |  |  |
     86.5 %    0.0 %    0.062 us :  |  |  |  +-(1) memcpy
                                 :  |  |  |  |
     86.5 %    0.0 %    0.239 us :  |  |  |  +-(1) reduce
     86.5 %    0.0 %    0.073 us :  |  |  |    (1) wcslen
                                 :  |  |  |
     86.9 %    0.3 %   32.692 us :  |  |  +-(1) calculate_prefix
     86.9 %    0.0 %    0.258 us :  |  |  |  +-(1) memset
                                 :  |  |  |  |
     87.2 %    0.3 %   31.851 us :  |  |  |  +-(1) search_for_prefix
     87.2 %    0.0 %    0.964 us :  |  |  |  |  +-(1) joinpath2
     87.2 %    0.0 %    0.145 us :  |  |  |  |  |  +-(2) wcslen
                                 :  |  |  |  |  |  |
     87.2 %    0.0 %    0.076 us :  |  |  |  |  |  +-(1) wcscpy
                                 :  |  |  |  |  |  |
     87.2 %    0.0 %    0.178 us :  |  |  |  |  |  +-(2) wcscat
                                 :  |  |  |  |  |
     87.4 %    0.2 %   15.800 us :  |  |  |  |  +-(1) isfile
     87.6 %    0.2 %   15.660 us :  |  |  |  |  | (1) _Py_wstat
     87.6 %    0.0 %    0.087 us :  |  |  |  |  |  +-(1) wcslen
                                 :  |  |  |  |  |  |
     87.6 %    0.1 %    6.053 us :  |  |  |  |  |  +-(98) wcstombs
                                 :  |  |  |  |  |  |
     87.7 %    0.0 %    1.548 us :  |  |  |  |  |  +-(1) __xstat64
                                 :  |  |  |  |  |
     87.7 %    0.0 %    0.388 us :  |  |  |  |  +-(1) safe_wcscpy
     87.7 %    0.0 %    0.060 us :  |  |  |  |  |  +-(1) wcslen
                                 :  |  |  |  |  |  |
     87.7 %    0.0 %    0.060 us :  |  |  |  |  |  +-(1) memcpy
                                 :  |  |  |  |  |
     87.7 %    0.0 %    1.120 us :  |  |  |  |  +-(2) joinpath
     87.7 %    0.0 %    0.199 us :  |  |  |  |  |  +-(4) wcslen
                                 :  |  |  |  |  |  |
     87.7 %    0.0 %    0.235 us :  |  |  |  |  |  +-(2) wcsncpy
                                 :  |  |  |  |  |
     87.8 %    0.1 %   13.059 us :  |  |  |  |  +-(1) ismodule
     87.8 %    0.0 %    0.795 us :  |  |  |  |     +-(1) joinpath2
     87.8 %    0.0 %    0.110 us :  |  |  |  |     |  +-(2) wcslen
                                 :  |  |  |  |     |  |
     87.8 %    0.0 %    0.071 us :  |  |  |  |     |  +-(1) wcscpy
                                 :  |  |  |  |     |  |
     87.8 %    0.0 %    0.145 us :  |  |  |  |     |  +-(2) wcscat
                                 :  |  |  |  |     |
     88.0 %    0.1 %   12.057 us :  |  |  |  |     +-(1) isfile
     88.1 %    0.1 %   11.957 us :  |  |  |  |       (1) _Py_wstat
     88.1 %    0.0 %    0.052 us :  |  |  |  |        +-(1) wcslen
                                 :  |  |  |  |        |
     88.1 %    0.1 %    4.817 us :  |  |  |  |        +-(78) wcstombs
                                 :  |  |  |  |        |
     88.1 %    0.0 %    0.829 us :  |  |  |  |        +-(1) __xstat64
                                 :  |  |  |  |
     88.1 %    0.0 %    0.051 us :  |  |  |  +-(1) wcslen
                                 :  |  |  |  |
     88.1 %    0.0 %    0.067 us :  |  |  |  +-(1) memcpy
                                 :  |  |  |
     88.2 %    0.0 %    1.964 us :  |  |  +-(1) calculate_zip_path
     88.2 %    0.0 %    1.755 us :  |  |  | (2) joinpath2
     88.2 %    0.0 %    0.236 us :  |  |  |  +-(4) wcslen
                                 :  |  |  |  |
     88.2 %    0.0 %    0.137 us :  |  |  |  +-(2) wcscpy
                                 :  |  |  |  |
     88.2 %    0.0 %    0.345 us :  |  |  |  +-(4) wcscat
                                 :  |  |  |
     88.5 %    0.3 %   24.495 us :  |  |  +-(1) calculate_exec_prefix
     88.5 %    0.0 %    0.200 us :  |  |  |  +-(1) memset
                                 :  |  |  |  |
     88.7 %    0.3 %   23.703 us :  |  |  |  +-(1) search_for_exec_prefix
     89.0 %    0.3 %   23.561 us :  |  |  |  | (1) calculate_pybuilddir
     89.0 %    0.0 %    0.843 us :  |  |  |  |  +-(1) joinpath2
     89.0 %    0.0 %    0.134 us :  |  |  |  |  |  +-(2) wcslen
                                 :  |  |  |  |  |  |
     89.0 %    0.0 %    0.059 us :  |  |  |  |  |  +-(1) wcscpy
                                 :  |  |  |  |  |  |
     89.0 %    0.0 %    0.177 us :  |  |  |  |  |  +-(2) wcscat
                                 :  |  |  |  |  |
     89.0 %    0.0 %    0.583 us :  |  |  |  |  +-(1) PySys_Audit
     89.0 %    0.0 %    0.171 us :  |  |  |  |  |  +-(1) _PyThreadState_GET
     89.0 %    0.0 %    0.050 us :  |  |  |  |  |  | (1) _PyRuntimeState_GetThreadState
                                 :  |  |  |  |  |  |
     89.0 %    0.0 %    0.258 us :  |  |  |  |  |  +-(1) sys_audit_tstate
     89.0 %    0.0 %    0.162 us :  |  |  |  |  |    (1) should_audit
     89.0 %    0.0 %    0.039 us :  |  |  |  |  |    (1) PyDTrace_AUDIT_ENABLED
                                 :  |  |  |  |  |
     89.0 %    0.1 %    5.464 us :  |  |  |  |  +-(89) wcstombs
                                 :  |  |  |  |  |
     89.0 %    0.0 %    0.075 us :  |  |  |  |  +-(1) wcslen
                                 :  |  |  |  |  |
     89.1 %    0.0 %    2.210 us :  |  |  |  |  +-(1) fopen64
                                 :  |  |  |  |  |
     89.1 %    0.0 %    0.072 us :  |  |  |  |  +-(1) fileno
                                 :  |  |  |  |  |
     89.1 %    0.0 %    0.500 us :  |  |  |  |  +-(2) fcntl64
                                 :  |  |  |  |  |
     89.1 %    0.0 %    3.242 us :  |  |  |  |  +-(1) fread
                                 :  |  |  |  |  |
     89.1 %    0.0 %    1.036 us :  |  |  |  |  +-(1) fclose
                                 :  |  |  |  |  |
     89.1 %    0.0 %    0.382 us :  |  |  |  |  +-(1) safe_wcscpy
     89.1 %    0.0 %    0.079 us :  |  |  |  |  |  +-(1) wcslen
                                 :  |  |  |  |  |  |
     89.1 %    0.0 %    0.058 us :  |  |  |  |  |  +-(1) memcpy
                                 :  |  |  |  |  |
     89.1 %    0.0 %    0.518 us :  |  |  |  |  +-(1) joinpath
     89.1 %    0.0 %    0.105 us :  |  |  |  |     +-(2) wcslen
                                 :  |  |  |  |     |
     89.1 %    0.0 %    0.133 us :  |  |  |  |     +-(1) wcsncpy
                                 :  |  |  |  |
     89.1 %    0.0 %    0.064 us :  |  |  |  +-(1) wcslen
                                 :  |  |  |  |
     89.1 %    0.0 %    0.052 us :  |  |  |  +-(1) memcpy
                                 :  |  |  |
     89.2 %    0.0 %    2.284 us :  |  |  +-(1) calculate_module_search_path
     89.2 %    0.0 %    0.285 us :  |  |  |  +-(4) wcslen
                                 :  |  |  |  |
     89.2 %    0.0 %    0.146 us :  |  |  |  +-(2) wcschr
                                 :  |  |  |  |
     89.2 %    0.0 %    0.594 us :  |  |  |  +-(6) wcscat
                                 :  |  |  |
     89.2 %    0.0 %    0.537 us :  |  |  +-(1) calculate_set_prefix
     89.2 %    0.0 %    0.071 us :  |  |  |  +-(1) wcslen
                                 :  |  |  |  |
     89.2 %    0.0 %    0.053 us :  |  |  |  +-(1) memcpy
                                 :  |  |  |
     89.2 %    0.0 %    0.440 us :  |  |  +-(1) calculate_set_exec_prefix
     89.2 %    0.0 %    0.070 us :  |  |     +-(1) wcslen
                                 :  |  |     |
     89.2 %    0.0 %    0.061 us :  |  |     +-(1) memcpy
                                 :  |  |
     89.2 %    0.0 %    0.238 us :  |  +-(1) calculate_free
                                 :  |
     89.5 %    0.3 %   27.733 us :  +-(1) _PySys_UpdateConfig
     89.5 %    0.0 %    0.389 us :  |  +-(5) memset
                                 :  |  |
     89.5 %    0.0 %    0.956 us :  |  +-(14) wcslen
                                 :  |  |
     89.5 %    0.0 %    0.857 us :  |  +-(14) strlen
                                 :  |  |
     89.5 %    0.0 %    0.887 us :  |  +-(15) memcpy
                                 :  |  |
     89.5 %    0.0 %    0.156 us :  |  +-(2) memcmp
                                 :  |  |
     89.5 %    0.0 %    0.559 us :  |  +-(13) _Py_DECREF
                                 :  |  |
     89.5 %    0.0 %    0.132 us :  |  +-(1) sys_create_xoptions_dict
                                 :  |  |
     89.5 %    0.0 %    1.006 us :  |  +-(1) _PySys_GetObject
     89.5 %    0.0 %    0.087 us :  |  |  +-(1) strlen
                                 :  |  |  |
     89.5 %    0.0 %    0.060 us :  |  |  +-(1) memcpy
                                 :  |  |  |
     89.5 %    0.0 %    0.073 us :  |  |  +-(1) memcmp
                                 :  |  |
     89.6 %    0.0 %    4.032 us :  |  +-(1) set_flags_from_config
     89.6 %    0.0 %    2.612 us :  |  | (16) _Py_XDECREF
     89.6 %    0.0 %    0.644 us :  |  | (16) _Py_DECREF
                                 :  |  |
     89.6 %    0.0 %    0.039 us :  |  +-(1) _PyErr_Occurred
                                 :  |
     90.7 %    1.1 %   99.333 us :  +-(77) PySys_GetObject
     90.8 %    0.2 %   14.765 us :  |  +-(77) _PyThreadState_GET
     90.9 %    0.0 %    3.710 us :  |  | (77) _PyRuntimeState_GetThreadState
                                 :  |  |
     91.6 %    0.7 %   69.849 us :  |  +-(77) _PySys_GetObject
     91.7 %    0.1 %    5.125 us :  |     +-(77) strlen
                                 :  |     |
     91.7 %    0.0 %    4.634 us :  |     +-(77) memcpy
                                 :  |     |
     91.8 %    0.1 %    4.867 us :  |     +-(77) memcmp
                                 :  |
     91.9 %    0.1 %   13.094 us :  +-(220) sem_trywait
                                 :  |
     92.0 %    0.0 %    3.970 us :  +-(71) sem_destroy
                                 :  |
     92.8 %    0.9 %   81.101 us :  +-(3) qsort
     93.1 %    0.3 %   24.289 us :  | (567) strcmp
                                 :  |
     93.1 %    0.0 %    0.215 us :  +-(1) sysconf
                                 :  |
     93.2 %    0.1 %   10.408 us :  +-(110) strncpy
                                 :  |
     93.2 %    0.0 %    0.372 us :  +-(4) memchr
                                 :  |
     93.2 %    0.0 %    0.051 us :  +-(1) time
                                 :  |
     93.3 %    0.1 %   13.462 us :  +-(2) localtime_r
                                 :  |
     95.3 %    1.9 %  180.828 us :  +-(2958) wcstombs
                                 :  |
     96.1 %    0.9 %   80.471 us :  +-(61) __xstat64
                                 :  |
     96.2 %    0.1 %    6.217 us :  +-(14) strerror
                                 :  |
     96.3 %    0.1 %   13.211 us :  +-(3) opendir
                                 :  |
     97.8 %    1.4 %  135.739 us :  +-(413) readdir64
                                 :  |
     98.0 %    0.2 %   18.120 us :  +-(3) closedir
                                 :  |
     98.3 %    0.4 %   34.524 us :  +-(13) open64
                                 :  |
     98.4 %    0.0 %    0.333 us :  +-(1) fcntl64
                                 :  |
     98.5 %    0.1 %    9.937 us :  +-(30) __fxstat64
                                 :  |
     98.5 %    0.1 %    8.337 us :  +-(19) isatty
                                 :  |
     98.6 %    0.1 %    6.078 us :  +-(29) lseek64
                                 :  |
     99.2 %    0.6 %   55.225 us :  +-(26) read
                                 :  |
     99.4 %    0.2 %   14.264 us :  +-(16) close
                                 :  |
     99.4 %    0.0 %    0.337 us :  +-(4) sigemptyset
                                 :  |
     99.5 %    0.1 %   10.119 us :  +-(68) sigaction
                                 :  |
     99.5 %    0.0 %    1.384 us :  +-(1) __libc_current_sigrtmin
                                 :  |
     99.5 %    0.0 %    0.630 us :  +-(1) __libc_current_sigrtmax
                                 :  |
     99.5 %    0.0 %    0.348 us :  +-(4) fileno
                                 :  |
     99.5 %    0.0 %    1.251 us :  +-(3) dup
                                 :  |
     99.6 %    0.1 %    5.832 us :  +-(3) PySys_SetObject
     99.6 %    0.0 %    1.038 us :  |  +-(3) _PyInterpreterState_GET
     99.6 %    0.0 %    0.706 us :  |  | (3) _PyThreadState_GET
     99.6 %    0.0 %    0.163 us :  |  | (3) _PyRuntimeState_GetThreadState
                                 :  |  |
     99.6 %    0.0 %    4.257 us :  |  +-(3) sys_set_object_str
     99.6 %    0.0 %    0.191 us :  |     +-(3) strlen
                                 :  |     |
     99.6 %    0.0 %    0.707 us :  |     +-(3) sys_set_object
                                 :  |     |
     99.6 %    0.0 %    0.556 us :  |     +-(3) _Py_XDECREF
     99.6 %    0.0 %    0.141 us :  |     | (3) _Py_DECREF
                                 :  |     |
     99.7 %    0.0 %    0.133 us :  |     +-(2) memcpy
                                 :  |     |
     99.7 %    0.0 %    0.070 us :  |     +-(1) memcmp
                                 :  |
     99.7 %    0.1 %    5.846 us :  +-(3) _PySys_SetObjectId
     99.7 %    0.0 %    0.809 us :  |  +-(3) _PyInterpreterState_GET
     99.7 %    0.0 %    0.518 us :  |  | (3) _PyThreadState_GET
     99.7 %    0.0 %    0.117 us :  |  | (3) _PyRuntimeState_GetThreadState
                                 :  |  |
     99.8 %    0.0 %    4.560 us :  |  +-(3) sys_set_object_id
     99.8 %    0.0 %    0.231 us :  |     +-(3) sem_wait
                                 :  |     |
     99.8 %    0.0 %    0.182 us :  |     +-(3) sem_post
                                 :  |     |
     99.8 %    0.0 %    0.185 us :  |     +-(3) strlen
                                 :  |     |
     99.8 %    0.0 %    0.118 us :  |     +-(2) memcpy
                                 :  |     |
     99.8 %    0.0 %    0.698 us :  |     +-(3) sys_set_object
                                 :  |     |
     99.8 %    0.0 %    0.062 us :  |     +-(1) memcmp
                                 :  |
     99.8 %    0.0 %    0.997 us :  +-(15) memmove
                                 :  |
     99.8 %    0.0 %    2.246 us :  +-(2) sys_getfilesystemencoding
     99.8 %    0.0 %    1.943 us :  | (2) sys_getfilesystemencoding_impl
     99.9 %    0.0 %    0.783 us :  |  +-(2) _PyInterpreterState_GET
     99.9 %    0.0 %    0.546 us :  |  | (2) _PyThreadState_GET
     99.9 %    0.0 %    0.109 us :  |  | (2) _PyRuntimeState_GetThreadState
                                 :  |  |
     99.9 %    0.0 %    0.262 us :  |  +-(2) wcslen
                                 :  |
     99.9 %    0.0 %    0.944 us :  +-(1) sys_getfilesystemencodeerrors
     99.9 %    0.0 %    0.835 us :  | (1) sys_getfilesystemencodeerrors_impl
     99.9 %    0.0 %    0.283 us :  |  +-(1) _PyInterpreterState_GET
     99.9 %    0.0 %    0.185 us :  |  | (1) _PyThreadState_GET
     99.9 %    0.0 %    0.045 us :  |  | (1) _PyRuntimeState_GetThreadState
                                 :  |  |
     99.9 %    0.0 %    0.107 us :  |  +-(1) wcslen
                                 :  |
     99.9 %    0.0 %    0.247 us :  +-(1) geteuid
                                 :  |
     99.9 %    0.0 %    0.145 us :  +-(1) getuid
                                 :  |
     99.9 %    0.0 %    0.151 us :  +-(1) getegid
                                 :  |
     99.9 %    0.0 %    0.115 us :  +-(1) getgid
                                 :  |
     99.9 %    0.0 %    2.546 us :  +-(4) _PySys_GetObjectId
     99.9 %    0.0 %    0.873 us :  |  +-(4) _PyThreadState_GET
     99.9 %    0.0 %    0.210 us :  |  | (4) _PyRuntimeState_GetThreadState
                                 :  |  |
     99.9 %    0.0 %    0.842 us :  |  +-(4) sys_get_object_id
                                 :  |
    100.0 %    0.0 %    0.926 us :  +-(1) _PySys_ClearAuditHooks
    100.0 %    0.0 %    0.090 us :  |  +-(1) _PyRuntimeState_GetFinalizing
                                 :  |  |
    100.0 %    0.0 %    0.467 us :  |  +-(1) _PySys_Audit
    100.0 %    0.0 %    0.363 us :  |    (1) sys_audit_tstate
    100.0 %    0.0 %    0.251 us :  |    (1) should_audit
    100.0 %    0.0 %    0.040 us :  |    (1) PyDTrace_AUDIT_ENABLED
                                 :  |
    100.0 %    0.0 %    0.183 us :  +-(1) pthread_key_delete
                                 :  |
    100.0 %    0.0 %    2.270 us :  +-(1) munmap
                                 :  |
    100.0 %    0.0 %    0.295 us :  +-(2) fflush

Note that the total time is much smaller than expected, given that normal un-traced execution took 17ms. Possibilities:

non-user execution was excluded
not all calls were recorded
recorded times were truncated by uftrace by some amount
recorded times are proportionally longer
recorded times are otherwise not accurate

uftrace only operates in user-space so the first one likely isn't it. The second one is unlikely, as are the fourth and fifth ones. ~~So something like the third one is most likely.~~ Actually, the results are missing things like the call to init_import_site(), so that second one is looking more likely.

Regardless, the results remain informative.

gvanrossum · 2021-08-09T23:35:22Z

Searching the 100 kHz flamegraph for "r_object" (the workhorse of marshal.loads) I see that quite a large fraction of time is spent here (it's in several separate piles). I didn't add the percentages but it looks close enough to match @nascheme's estimate of 27%. Of course, the initialization doesn't have a lot of unused code (I saw a little fluff in site.py) so making marshal.loads lazy won't help much. (OTOH making it faster, e.g. via Experiment B #65, would pay off). The scheme we discussed this morning (issue TBD) might be even more effective.

OTOH, for some low-hanging fruit, @iritkatriel first remarked that it's spending a lot of time in GC. This effect seems the strongest in the pile on top of get_frozen_object() -- it spends 60% of its time in PyTuple_New() and most of that is in gc_collect_main(). Now, get_frozen_object() only represents 2.62% of the total (main() is 48%). But still. Maybe gc just isn't well-tuned for quickly loading code objects? Or maybe it isn't tuned at all?

gvanrossum · 2021-08-09T23:36:21Z

@ericsnowcurrently Would a flamegraph with more samples/sec (e.g. 10,000 Hz) be useful? I'm worried that we have only ~2000 samples in total.

ericsnowcurrently · 2021-08-10T02:41:38Z

We did 100,000 hz. We could certainly go higher. (I was hoping the data generated by uftrace would be exhaustive, and thus give us the full picture, but it's not giving me the results I'm expecting.)

gvanrossum · 2021-08-25T21:59:08Z

FYI I meant e.g. 1,000,000 Hz. 10,000 Hz would be lower resolution, and result in only 200 samples. Flame graphs are hard!

nascheme · 2021-08-25T22:14:14Z

Profiling is hard to do. I think there are some problems with increasing the frequency too high. Definitely you are influencing the results due to the extra overhead of saving the profile stats. To get more samples, I created a loop that ran the startup hundreds or thousands of times. That has its own problems since the effect of various caches is changed on repeated runs like that (i.e. in a tight loop).

gvanrossum · 2021-11-09T23:39:32Z

Once deep-freeze lands it would be nice to regenerate the flame graph to see if there are now new bottlenecks that we could attack.

markshannon · 2024-05-07T09:11:12Z

We now have profiling information: https://github.com/faster-cpython/benchmarking-public/tree/main/profiling

markshannon · 2024-05-07T09:12:58Z

The per-benchmark profiles for the "startup" benchmarks should give us the information we need.

gvanrossum · 2024-05-07T15:25:22Z

We now have profiling information: https://github.com/faster-cpython/benchmarking-public/tree/main/profiling

There's little guidance about what the data files found there mean, or even how one would visualize them.

ericsnowcurrently self-assigned this Jul 27, 2021

ericsnowcurrently mentioned this issue Jul 27, 2021

[profiling] Add profiling instrumentation centered on the eval loop #25

Closed

ericsnowcurrently mentioned this issue Jul 28, 2021

[profiling] Gather low-level profile data for the various benchmarks. #76

Closed

10 tasks

gvanrossum mentioned this issue Aug 9, 2021

Faster startup -- Experiment C -- lazy unmarshalling #66

Closed

gramster added this to Fancy CPython Board Jan 10, 2022

gramster moved this to Todo in Fancy CPython Board Jan 10, 2022

ericsnowcurrently removed their assignment Jul 7, 2022

markshannon closed this as completed May 7, 2024

github-project-automation bot moved this from Todo to Done in Fancy CPython Board May 7, 2024

markshannon reopened this May 7, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[profiling] Profile/analyze runtime startup (and shutdown). #75

[profiling] Profile/analyze runtime startup (and shutdown). #75

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

methane commented Jul 28, 2021

ericsnowcurrently commented Jul 28, 2021 •

edited

Loading

ericsnowcurrently commented Jul 28, 2021

ericsnowcurrently commented Jul 28, 2021

methane commented Jul 29, 2021

ericsnowcurrently commented Aug 5, 2021 •

edited

Loading

gvanrossum commented Aug 9, 2021

gvanrossum commented Aug 9, 2021

ericsnowcurrently commented Aug 10, 2021

gvanrossum commented Aug 25, 2021

nascheme commented Aug 25, 2021 •

edited by gvanrossum

Loading

gvanrossum commented Nov 9, 2021

markshannon commented May 7, 2024

markshannon commented May 7, 2024

gvanrossum commented May 7, 2024

[profiling] Profile/analyze runtime startup (and shutdown). #75

[profiling] Profile/analyze runtime startup (and shutdown). #75

Comments

ericsnowcurrently commented Jul 27, 2021 • edited Loading

ericsnowcurrently commented Jul 27, 2021 • edited Loading

ericsnowcurrently commented Jul 27, 2021 • edited Loading

ericsnowcurrently commented Jul 27, 2021 • edited Loading

methane commented Jul 28, 2021

ericsnowcurrently commented Jul 28, 2021 • edited Loading

ericsnowcurrently commented Jul 28, 2021

ericsnowcurrently commented Jul 28, 2021

methane commented Jul 29, 2021

ericsnowcurrently commented Aug 5, 2021 • edited Loading

gvanrossum commented Aug 9, 2021

gvanrossum commented Aug 9, 2021

ericsnowcurrently commented Aug 10, 2021

gvanrossum commented Aug 25, 2021

nascheme commented Aug 25, 2021 • edited by gvanrossum Loading

gvanrossum commented Nov 9, 2021

markshannon commented May 7, 2024

markshannon commented May 7, 2024

gvanrossum commented May 7, 2024

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

ericsnowcurrently commented Jul 27, 2021 •

edited

Loading

ericsnowcurrently commented Jul 28, 2021 •

edited

Loading

ericsnowcurrently commented Aug 5, 2021 •

edited

Loading

nascheme commented Aug 25, 2021 •

edited by gvanrossum

Loading