| 1 |
-----BEGIN PGP SIGNED MESSAGE----- |
| 2 |
Hash: SHA512 |
| 3 |
|
| 4 |
Hi, |
| 5 |
|
| 6 |
I did some profiling now. |
| 7 |
|
| 8 |
`ansible-doc -l` that runs on debian under 10 seconds, need around 60 |
| 9 |
seconds on Gentoo. |
| 10 |
|
| 11 |
The top most stuff on Gentoo is: |
| 12 |
ncalls tottime percall cumtime percall filename:lineno(function) |
| 13 |
384/1 0.020 0.000 81.471 81.471 {built-in method builtins.exec} |
| 14 |
1 0.000 0.000 81.471 81.471 ansible-doc:11(<module>) |
| 15 |
1 0.000 0.000 81.463 81.463 <string>:21(<module>) |
| 16 |
1 0.001 0.001 79.903 79.903 doc.py:85(run) |
| 17 |
1 0.094 0.094 79.628 79.628 doc.py:239(get_plugin_list_text) |
| 18 |
1652 0.414 0.000 79.150 0.048 plugin_docs.py:111(get_docstring) |
| 19 |
2866 0.010 0.000 74.784 0.026 constructor.py:33(get_single_data) |
| 20 |
2866 0.015 0.000 71.240 0.025 composer.py:29(get_single_node) |
| 21 |
2866 0.011 0.000 70.763 0.025 composer.py:50(compose_document) |
| 22 |
261720/2866 1.204 0.000 70.722 0.025 composer.py:63(compose_node) |
| 23 |
30138/2866 0.536 0.000 70.324 0.025 composer.py:117(compose_mapping_node) |
| 24 |
849269 1.239 0.000 66.618 0.000 parser.py:94(check_event) |
| 25 |
2129330 3.342 0.000 56.505 0.000 scanner.py:113(check_token) |
| 26 |
1652 0.265 0.000 50.278 0.030 plugin_docs.py:22(read_docstring) |
| 27 |
365903 1.750 0.000 45.470 0.000 scanner.py:153(fetch_more_tokens) |
| 28 |
36013/36010 0.349 0.000 35.274 0.001 composer.py:99(compose_sequence_node) |
| 29 |
174238 0.400 0.000 30.847 0.000 scanner.py:665(fetch_plain) |
| 30 |
174238 7.900 0.000 29.059 0.000 scanner.py:1266(scan_plain) |
| 31 |
1652 0.099 0.000 28.458 0.017 plugin_docs.py:61(add_fragments) |
| 32 |
63108 0.274 0.000 27.182 0.000 parser.py:381(parse_block_sequence_entry) |
| 33 |
26043 0.068 0.000 18.667 0.001 parser.py:376(parse_block_sequence_first_entry) |
| 34 |
100663 0.354 0.000 17.380 0.000 parser.py:446(parse_block_mapping_value) |
| 35 |
130406 0.518 0.000 13.148 0.000 parser.py:427(parse_block_mapping_key) |
| 36 |
2910923 10.525 0.000 10.934 0.000 reader.py:99(forward) |
| 37 |
261708 2.237 0.000 10.598 0.000 parser.py:273(parse_node) |
| 38 |
3413735 4.102 0.000 9.327 0.000 scanner.py:142(need_more_tokens) |
| 39 |
685037 3.354 0.000 8.933 0.000 scanner.py:1313(scan_plain_spaces) |
| 40 |
201314 0.243 0.000 8.660 0.000 parser.py:270(parse_block_node_or_indentless_sequence) |
| 41 |
12669695 5.800 0.000 5.801 0.000 reader.py:87(peek) |
| 42 |
365903 1.685 0.000 4.873 0.000 scanner.py:749(scan_to_next_token) |
| 43 |
3500035 4.606 0.000 4.606 0.000 scanner.py:276(stale_possible_simple_keys) |
| 44 |
1482821 2.620 0.000 4.096 0.000 reader.py:114(get_mark) |
| 45 |
1654 0.006 0.000 3.930 0.002 ast.py:30(parse) |
| 46 |
1657 3.925 0.002 3.926 0.002 {built-in method builtins.compile} |
| 47 |
9549 0.039 0.000 3.653 0.000 parser.py:402(parse_indentless_sequence_entry) |
| 48 |
2866 0.105 0.000 3.535 0.001 constructor.py:40(construct_document) |
| 49 |
581538 0.951 0.000 2.928 0.000 scanner.py:132(get_token) |
| 50 |
1751957 2.495 0.000 2.802 0.000 reader.py:94(prefix) |
| 51 |
20951 0.050 0.000 2.559 0.000 scanner.py:654(fetch_flow_scalar) |
| 52 |
59190/32460 0.103 0.000 2.481 0.000 constructor.py:46(construct_yaml_map) |
| 53 |
19816 0.091 0.000 2.390 0.000 parser.py:476(parse_flow_sequence_entry) |
| 54 |
20951 0.274 0.000 2.366 0.000 scanner.py:1131(scan_flow_scalar) |
| 55 |
261720 0.838 0.000 2.358 0.000 constructor.py:53(construct_object) |
| 56 |
29595 0.360 0.000 2.326 0.000 constructor.py:53(construct_mapping) |
| 57 |
101197 0.811 0.000 2.063 0.000 scanner.py:542(fetch_value) |
| 58 |
29743 0.060 0.000 1.966 0.000 parser.py:422(parse_block_mapping_first_key) |
| 59 |
195569 0.797 0.000 1.916 0.000 composer.py:88(compose_scalar_node) |
| 60 |
11024 0.010 0.000 1.913 0.000 scanner.py:651(fetch_double) |
| 61 |
46107 0.064 0.000 1.750 0.000 parser.py:264(parse_block_node) |
| 62 |
539958 0.732 0.000 1.736 0.000 scanner.py:1418(scan_line_break) |
| 63 |
|
| 64 |
While the top most costy calls on debian are: |
| 65 |
ncalls tottime percall cumtime percall filename:lineno(function) |
| 66 |
1 0.002 0.002 7.881 7.881 ansible-doc:21(<module>) |
| 67 |
1 0.000 0.000 7.378 7.378 doc.py:85(run) |
| 68 |
1 0.050 0.050 7.244 7.244 doc.py:239(get_plugin_list_text) |
| 69 |
1652 0.193 0.000 7.026 0.004 plugin_docs.py:111(get_docstring) |
| 70 |
1652 0.083 0.000 5.589 0.003 plugin_docs.py:22(read_docstring) |
| 71 |
2866 0.005 0.000 3.503 0.001 constructor.py:35(get_single_data) |
| 72 |
1654 0.003 0.000 2.554 0.002 ast.py:32(parse) |
| 73 |
1657 2.551 0.002 2.551 0.002 {compile} |
| 74 |
2866 0.047 0.000 2.013 0.001 constructor.py:42(construct_document) |
| 75 |
2866 0.858 0.000 1.485 0.001 {method 'get_single_node' of '_yaml.CParser' objects} |
| 76 |
59190/32460 0.057 0.000 1.465 0.000 constructor.py:46(construct_yaml_map) |
| 77 |
261720 0.534 0.000 1.430 0.000 constructor.py:55(construct_object) |
| 78 |
29595 0.189 0.000 1.373 0.000 constructor.py:53(construct_mapping) |
| 79 |
1652 0.033 0.000 1.244 0.001 plugin_docs.py:61(add_fragments) |
| 80 |
171844 0.291 0.000 0.728 0.000 constructor.py:84(construct_yaml_str) |
| 81 |
1797 0.496 0.000 0.496 0.000 {method 'read' of 'file' objects} |
| 82 |
71252/71249 0.080 0.000 0.495 0.000 constructor.py:112(construct_yaml_seq) |
| 83 |
36013 0.045 0.000 0.382 0.000 constructor.py:112(construct_sequence) |
| 84 |
261720 0.286 0.000 0.377 0.000 resolver.py:143(resolve) |
| 85 |
195569 0.132 0.000 0.254 0.000 constructor.py:163(construct_scalar) |
| 86 |
1 0.003 0.003 0.232 0.232 __init__.py:16(<module>) |
| 87 |
266660 0.171 0.000 0.171 0.000 objects.py:41(_set_ansible_position) |
| 88 |
34/20 0.004 0.000 0.170 0.009 {__import__} |
| 89 |
533 0.002 0.000 0.157 0.000 re.py:230(_compile) |
| 90 |
168 0.000 0.000 0.156 0.001 re.py:192(compile) |
| 91 |
163 0.001 0.000 0.155 0.001 sre_compile.py:567(compile) |
| 92 |
1 0.001 0.001 0.152 0.152 constants.py:5(<module>) |
| 93 |
834730/834729 0.134 0.000 0.137 0.000 {isinstance} |
| 94 |
2 0.000 0.000 0.133 0.066 __init__.py:3078(_call_aside) |
| 95 |
1 0.000 0.000 0.133 0.133 __init__.py:3095(_initialize_master_working_set) |
| 96 |
14546 0.127 0.000 0.127 0.000 {posix.stat} |
| 97 |
266660 0.124 0.000 0.124 0.000 constructor.py:121(_node_position_info) |
| 98 |
36 0.001 0.000 0.121 0.003 __init__.py:598(add_entry) |
| 99 |
195569 0.120 0.000 0.120 0.000 nodes.py:27(__init__) |
| 100 |
272 0.001 0.000 0.116 0.000 __init__.py:1930(find_on_path) |
| 101 |
9941 0.013 0.000 0.112 0.000 genericpath.py:46(isdir) |
| 102 |
|
| 103 |
Any idea why there is that difference in call time? |
| 104 |
|
| 105 |
Regards |
| 106 |
Klaus |
| 107 |
- -- |
| 108 |
Klaus Ethgen http://www.ethgen.ch/ |
| 109 |
pub 4096R/4E20AF1C 2011-05-16 Klaus Ethgen <Klaus@××××××.ch> |
| 110 |
Fingerprint: 85D4 CA42 952C 949B 1753 62B3 79D0 B06F 4E20 AF1C |
| 111 |
-----BEGIN PGP SIGNATURE----- |
| 112 |
Comment: Charset: ISO-8859-1 |
| 113 |
|
| 114 |
iQGzBAEBCgAdFiEEMWF28vh4/UMJJLQEpnwKsYAZ9qwFAlsxRF8ACgkQpnwKsYAZ |
| 115 |
9qyXfAv7BDfNd/UjLE0sKtV0r/GjMTjbjcx6k70O4rgOMIHYMlm2RuDNLNefhV7i |
| 116 |
+qcLaP1HFHByi/Appx1rU6/g68J8/j+x+cq0YVKLQOv0c/Ol3Yu+KFxxAq78gScO |
| 117 |
CFqL30Pf9oexTB35VpeoSrYGhEbt0Y6/V/n7d2bOybNtELvlIXYuYN/aadlImIhi |
| 118 |
ntmV1lrrigAn4lVM/kt6uH8HUkCvly3fI0RmTNjmhpUMS5FgpjvFVM0EsaCRpAEF |
| 119 |
Jp/V6xLd30zmwCcIOvO3L9udCL5Y0KNPB/gKHxFRF74FZAiwUdAjF3lp7Szve3sp |
| 120 |
TfVJILlz+iWjMg3rDeb5v+6E3LeeJHbpsBywkO1YcteEtDKsSbPBkiBvYFL/T7D8 |
| 121 |
bvDAE9Ns+xDtoExiMup+NRlXsm1R7I+Cl/NjkGXDEFPdR91s+34ngQm+qGfzbGHH |
| 122 |
1XGcsobHEyX9iALEeHrDlDd7yLyZjAERqBHkL44cBb84F9i6zgp0Wr89FqeKR2Ai |
| 123 |
L/U1KAYt |
| 124 |
=S6B9 |
| 125 |
-----END PGP SIGNATURE----- |
Archives