Univention Bugzilla – Bug 39632
Performance optimization for App Center
Last modified: 2017-01-17 11:50:25 CET
Startup performance for the UMC module is mediocre. We should elaborate ways to enhance execution speed. One way might be caching of UCR. Currently, UCR is initialized in a lot of local functions. This way one does not have to think about thread safety, concurrent processes and so on. But it may cost too much time. LDAP lookups may also be reduced, although this has already seen one patch.
use univention.management.console.modules.decorators.reloading_ucr for a x-milliseconds cached UCR instance.
(In reply to Florian Best from comment #1) > use univention.management.console.modules.decorators.reloading_ucr for a > x-milliseconds cached UCR instance. Yes, something like that. But I cannot use UMC in univention-appcenter
Finding the .meta file for the ini file in App.from_ini() takes a considerable amount of time. Every .meta file is parsed until one is found with ID=$app in it... This needs to be optimized.
(In reply to Dirk Wiesenthal from comment #3) > This needs to be optimized. Done in Bug#38891 - this introduced the .meta files, so optimizations are allowed while the bug is not CLOSED.
A test case for the App Center performance has already been implemented, cf. Bug 38545.
It took me about one minute to deflate all files (note: this is the very first day of UCS 4.1! In six months this number should have increased by a lot) 3504 actions.install.container.9eac 15-11-13 21:31:39 [ INFO]: 440 file(s) are new 3504 actions.install.container.9eac 15-11-13 21:31:39 [ INFO]: Downloading "https://appcenter-test.software-univention.de/meta-inf/4.1/all.tar.gz"... 3504 actions.install.container.9eac 15-11-13 21:32:18 [ INFO]: Registering component for filewave
The 3 most expensive things during "univention-appcenter update" are the SSL handshake, decoding bytes to unicode and the MD5 calculations: ncalls tottime percall cumtime percall filename:lineno(function) 4 0.191 0.048 0.191 0.048 {built-in method do_handshake} 151610 0.155 0.000 0.155 0.000 {_codecs.utf_8_decode} 1 0.151 0.151 0.456 0.456 update.py:306(_read_index_json) The calculation of the MD5 hash is done very often in 'univention-app update'. 528 0.011 0.000 0.053 0.000 utils.py:208(get_md5_from_file) Maybe it also helps to re.compile the regular expressions which are used often (and it doesn't help to compile them every time as done in appcenter.utils.call_process()). E.g. the ones which are passed directly at the App class as AppAttribute. But this shouldn't be a big performance leak: ncalls tottime percall cumtime percall filename:lineno(function) 138/137 0.001 0.000 0.055 0.000 sre_parse.py:663(parse)
(In reply to Florian Best from comment #7) > The 3 most expensive things during "univention-appcenter update" are the SSL > handshake, decoding bytes to unicode and the MD5 calculations: > ncalls tottime percall cumtime percall filename:lineno(function) > 4 0.191 0.048 0.191 0.048 {built-in method do_handshake} > 151610 0.155 0.000 0.155 0.000 {_codecs.utf_8_decode} > 1 0.151 0.151 0.456 0.456 update.py:306(_read_index_json) > > The calculation of the MD5 hash is done very often in 'univention-app > update'. > 528 0.011 0.000 0.053 0.000 utils.py:208(get_md5_from_file) > > Maybe it also helps to re.compile the regular expressions which are used > often (and it doesn't help to compile them every time as done in > appcenter.utils.call_process()). E.g. the ones which are passed directly at > the App class as AppAttribute. But this shouldn't be a big performance leak: > ncalls tottime percall cumtime percall filename:lineno(function) > 138/137 0.001 0.000 0.055 0.000 sre_parse.py:663(parse) Thanks, I opened Bug#40360
@Dirk: See Bug 38545, comment 4: > Current results are as follows... not sure whether the test should be > re-activated. The first round probably syncs app center data. > > @Dirk: What do you think? > > > root@ucs-dc-4621:~# /usr/share/ucs-test/20_appcenter/60_check_appcenter_performance > > ### FAIL ### > > The appcenter answered too slow > > Threshold is 5 sec; Appcenter replied in 12.5546138287 sec. > > ### ### > > Starting 1 ucs-test at 2015-12-22 04:35:09 to /dev/null > > Check the performance for requests against the UMC appcenter..................................................................... Test failed > > > > root@ucs-dc-4621:~# /usr/share/ucs-test/20_appcenter/60_check_appcenter_performance > > Starting 1 ucs-test at 2015-12-22 04:35:20 to /dev/null > > Check the performance for requests against the UMC appcenter..................................................................... Test passed > > > > root@ucs-dc-4621:~# /usr/share/ucs-test/20_appcenter/60_check_appcenter_performance > > Starting 1 ucs-test at 2015-12-22 04:35:35 to /dev/null > > Check the performance for requests against the UMC appcenter..................................................................... Test passed From Bug 38545, comment 5: > [..] > Would it be possible to sync the app center data as part of the system-setup > or with a cron job? I think a cron job would be nice to avoid syncing the data which leads to bad performance with the first request.
(In reply to Alexander Kläser from comment #9) > I think a cron job would be nice to avoid syncing the data which leads to > bad performance with the first request. Actually, there is a cron job that does that, though not directly univention-app update. But it is called as part of univention-upgrade which runs once a day.
Startup performance is okay. If you have more ideas how to improve performance, open a separate bug.
(In reply to Dirk Wiesenthal from comment #11) > Startup performance is okay. If you have more ideas how to improve > performance, open a separate bug. It takes about 6 to 7 seconds to start the App Center on demo.univention.de. Even the second time I open it. Where is the time going?
Performance is bad at the moment. Has to do with READMEs read after initialization. Needs to be fixed.
All UCS@school jenkins tests currently fail, in the join log I see: http://jenkins.knut.univention.de:8080/job/UCSschool%204.1/job/UCSschool%204.0%20to%204.1%20Multiserver/ws/SambaVersion/s4-school-only/join.log RUNNING 30univention-appcenter.inst … Waiting for activation of the extension object univention-app: OK Waiting for activation of the extension object 66univention-appcenter_app: OK Waiting for activation of the extension object appcenter/app:....................................................ERROR: Master did not mark the extension object active within 180 seconds. ERROR ucs_registerLDAPExtension: registraton of /usr/share/univention-appcenter/app.py failed. EXITCODE=1
Fixed: Removed: open(readme) and the like even for cached apps Regression introduced in the patch for Self Service Added: Two phase appcenter/query: 1) Only get very basic data like "id", "name", "is_installed" -> Already view the Gallery 2) Get everything, "readme", "long_description" -> Be able to open App instantly Operates on the same store object to not jump in the gallery when loading phase 2. Speeds up the gallery view (for me: 1s vs 7s). Although it now takes 8s until the gallery is completely ready. univention-appcenter (5.0.23-32)
I re-enabled the performance test case: > ucs-test (6.0.37-34): > r75640 | Bug #39632: update and enable 20_appcenter/60_check_appcenter_performance
The changes look fine so far. I only identified a really minor problem when there are no components installed and one installs a Univention component via CLI (univention-install / apt-get install). The component will disappear after a 2-3 seconds when opening the App Center. The meta category "Installed Apps" is not visible from the beginning and it will not be shown after the second longer App Center query. However, the chance that someone runs into this problem are fairly low, and additionally this is just a minor appearance problem and nothing critical. Changes: OK YAML file: OK Merge to 4.2-0: OK
I adjusted the timeouts for the test again to 4.5 sec. > ucs-test (6.0.37-37): > r75676 | Bug #39632: adjust timeout in 20_appcenter/60_check_appcenter_performance
<http://errata.software-univention.de/ucs/4.1/373.html>
(In reply to Alexander Kläser from comment #18) > I adjusted the timeouts for the test again to 4.5 sec. > > > ucs-test (6.0.37-37): > > r75676 | Bug #39632: adjust timeout in 20_appcenter/60_check_appcenter_performance I merged the changes for the test to 4.2-0. > ucs-test (7.0.7-3): > r75857 | Bug #39632: adjust timeout for 20_appcenter/60_check_appcenter_performance > r75856 | Bug #39632: update and enable 20_appcenter/60_check_appcenter_performance