{"id":7752,"date":"2015-01-21T09:30:56","date_gmt":"2015-01-21T09:30:56","guid":{"rendered":"https:\/\/owncloud.com\/?p=7752"},"modified":"2015-01-21T09:30:56","modified_gmt":"2015-01-21T09:30:56","slug":"blackfire-io-and-recent-performance-optimizations-in-owncloud","status":"publish","type":"post","link":"https:\/\/owncloud.com\/de\/blogs\/blackfire-io-and-recent-performance-optimizations-in-owncloud\/","title":{"rendered":"Blackfire and recent performance optimizations in ownCloud"},"content":{"rendered":"<p><div id=\"attachment_7757\" style=\"width: 289px\" class=\"wp-caption alignright\"><a href=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/beginning.png\"><img loading=\"lazy\" decoding=\"async\" aria-describedby=\"caption-attachment-7757\" src=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/beginning-269x300.png\" alt=\"The graph that started it\" width=\"269\" height=\"300\" class=\"size-medium wp-image-7757\" \/><\/a><p id=\"caption-attachment-7757\" class=\"wp-caption-text\">The graph that started it<\/p><\/div><br \/>\nA little under two weeks ago, a performance improvement in <a href=\"http:\/\/ownCloud.org\" target=\"_blank\" rel=\"noopener\">ownCloud<\/a> was <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13192#issuecomment-69353656\" target=\"_blank\" rel=\"noopener\">accompanied by a graph<\/a> showing the difference in code execution time. The tool used to generate the graph was <a href=\"https:\/\/blackfire.io\/\" target=\"_blank\" rel=\"noopener\">Blackfire<\/a>, a powerful and easy to use PHP profiler. Since that first graph, many more have been created and much code has been optimized.<\/p>\n<h2>The first optimizations<\/h2>\n<p>The easy to read and intuitive Blackfire images quickly spread over Github and led to a speedup in the AppStore, thanks to caching the responses from <a href=\"http:\/\/apps.owncloud.com\">apps.owncloud.com<\/a>. While the first fetching data from the app store takes a few seconds, subsequent page loads can rely on the cache, making a big perceptible difference for the end user, easily speeding up operations 20 times. The developer making the changes, Lukas, <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13212#issuecomment-69383926\" target=\"_blank\" rel=\"noopener\">provided a nice graph<\/a> showing the difference.<\/p>\n<div id=\"attachment_7760\" style=\"width: 718px\" class=\"wp-caption alignnone\"><a href=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/LukasReschke-on-BlackFire.png\"><img loading=\"lazy\" decoding=\"async\" aria-describedby=\"caption-attachment-7760\" src=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/LukasReschke-on-BlackFire.png\" alt=\"LukasReschke on BlackFire\" width=\"698\" height=\"141\" class=\"size-full wp-image-7760\" \/><\/a><p id=\"caption-attachment-7760\" class=\"wp-caption-text\">LukasReschke on Blackfire<\/p><\/div>\n<h3>Getting serious<\/h3>\n<p>Lukas, who &#8218;discovered&#8216; Blackfire initially, started to simply upload files and use the profiler to see what took a lot of time. This resulted in a series of changes to file related operations, collected in <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13221\" target=\"_blank\" rel=\"noopener\">this Github issue<\/a> &#8212; starting small with a <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13223\" target=\"_blank\" rel=\"noopener\">4% performance gain on the processing of <em>`normalizeUnicode`<\/em><\/a>, adding a <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13224\" target=\"_blank\" rel=\"noopener\">simplification to a check on paths<\/a> and ending with a <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13235\" target=\"_blank\" rel=\"noopener\">performance boost of 24%<\/a> for simple searches.<\/p>\n<h3>Speed up file deletion<\/h3>\n<p>Another extensive profiling session resulted in even more impressive results after Thomas noticed that deleting a folder with 3,000+ files in it took a huge amount of time to get processed. In total over 35 minutes, showing in the profiler <a href=\"https:\/\/blackfire.io\/profiles\/6c752b06-e1ba-48f6-a154-7cfc7df76f80\/graph\" target=\"_blank\" rel=\"noopener\">as this graph<\/a>. It shows clearly that the bottleneck are nearly 40,000 SQL requests which are causing over 70% of the total request time.<\/p>\n<p>In the first iteration the request time went <a href=\"https:\/\/blackfire.io\/profiles\/1a32901e-98a8-4663-abf4-f905d7b4e602\/graph\" target=\"_blank\" rel=\"noopener\">down to 10 minutes<a\/> by <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13394\" target=\"_blank\" rel=\"noopener\">reducing the SQL queries by a factor of 10<\/a>. Now, another interesting bottleneck showed up: the PHP method <em>`strlen`<\/em> was called over 60,000 times by a component from a third party library that ownCloud uses, ZendSearch, from <a href=\"https:\/\/github.com\/zendframework\/\" target=\"_blank\" rel=\"noopener\">Zend Framework<\/a>. Focus moved to this library and it became clear that <em>`strlen`<\/em> was used to just decide if a string has a defined length. Somebody came up with the idea of simply using the native language construct <em>`isset`<\/em> rather than a function like <em>`strlen`<\/em>. Instead of doing this&#8230;<\/p>\n<pre>if (strlen($name) > 49) {\n\t...\n}<\/pre>\n<p>&#8230; you can do this which results in the exact same behavior, except that it is a lot faster:<\/p>\n<pre>if (isset($name[49])) {\n\t...\n}<\/pre>\n<p><div id=\"attachment_7759\" style=\"width: 320px\" class=\"wp-caption alignright\"><a href=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/zendframework.png\"><img loading=\"lazy\" decoding=\"async\" aria-describedby=\"caption-attachment-7759\" src=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/zendframework-300x96.png\" alt=\"The difference in ZendSearch\" width=\"300\" height=\"96\" class=\"size-medium wp-image-7759\" \/><\/a><p id=\"caption-attachment-7759\" class=\"wp-caption-text\">The difference in ZendSearch<\/p><\/div><br \/>\nWe provided a patch <a href=\"https:\/\/github.com\/zendframework\/ZendSearch\/pull\/19\" target=\"_blank\" rel=\"noopener\">upstream<\/a> which reduces the load for this code path greatly.<\/p>\n<p>For the deletion use case, the improvement moved the instant processing to update the search index to a background job. This results in the execution time going down to just <a href=\"https:\/\/blackfire.io\/profiles\/7efb175a-68cf-4e4e-8970-2d7bd6089eff\/graph\" target=\"_blank\" rel=\"noopener\">1 minute<\/a>! There is still room for further improvements but it is a great first step and it took only a moderate amount of effort to achieve. The change from <em>`strlen`<\/em> to <em>`isset`<\/em> turned out to also be <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13236\" target=\"_blank\" rel=\"noopener\">relevant in ownCloud code<\/a>, bringing a nice 20% increase in speed for processing a million path lookups.<\/p>\n<div id=\"attachment_7758\" style=\"width: 320px\" class=\"wp-caption alignright\"><a href=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/punic-1.png\"><img loading=\"lazy\" decoding=\"async\" aria-describedby=\"caption-attachment-7758\" src=\"https:\/\/owncloud.com\/wp-content\/uploads\/2015\/01\/punic-1-300x254.png\" alt=\"impact of the first change in Punic\" width=\"300\" height=\"254\" class=\"size-medium wp-image-7758\" \/><\/a><p id=\"caption-attachment-7758\" class=\"wp-caption-text\">Impact of the first change in Punic<\/p><\/div>\n<h3>Four Punic contributions<\/h3>\n<p>A debugging session led to finding another <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13434\" target=\"_blank\" rel=\"noopener\">performance bottleneck<\/a> with very large folders and another set of upstream improvements. The first patch going in the <a href=\"http:\/\/punic.github.io\/\" target=\"_blank\" rel=\"noopener\">Punic<\/a> localization library was <a href=\"https:\/\/github.com\/punic\/punic\/pull\/30\" target=\"_blank\" rel=\"noopener\">caching <em>getTimezoneNameNoLocationSpecific<\/em><\/a>, followed by <a href=\"https:\/\/github.com\/punic\/punic\/pull\/31\" target=\"_blank\" rel=\"noopener\">this<\/a> and <a href=\"https:\/\/github.com\/punic\/punic\/pull\/36\" target=\"_blank\" rel=\"noopener\">this<\/a>. Familiar by now might be a patch to <a href=\"https:\/\/github.com\/punic\/punic\/pull\/39\" target=\"_blank\" rel=\"noopener\">use <em>isset()<\/em> instead of <em>strlen()<\/em><\/a>! On the ownCloud side, <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13438\" target=\"_blank\" rel=\"noopener\">reusing the array key of mimetypes<\/a> helped improve performance and the session also <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13440\" target=\"_blank\" rel=\"noopener\">found a bug<\/a> which was <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13478\" target=\"_blank\" rel=\"noopener\">subsequently fixed<\/a>. More ideas <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13434#issuecomment-70475213\" target=\"_blank\" rel=\"noopener\">are still coming in<\/a> while this issue is tackled.<\/p>\n<h3>Architectural impact<\/h3>\n<p>Not all performance issues can be relatively easily fixed. Lukas discovered that the custom OC_Autoloader in ownCloud is <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13241\" target=\"_blank\" rel=\"noopener\">quite a bit slower<\/a> than the Composer loader we are transitioning to. These loaders bring in functionality from third party libraries ownCloud uses when needed in a piece of code. The OC_Autoloader is the &#8218;old&#8216; way ownCloud has been handling that and the fact that OC_Autoloader wasn&#8217;t fast had been <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/9619\" target=\"_blank\" rel=\"noopener\">noted before<\/a>. ownCloud 8 will introduce the <a href=\"https:\/\/getcomposer.org\/\" target=\"_blank\" rel=\"noopener\">Composer loader<\/a>, a dependency manager strongly inspired by Node&#8217;s npm and Ruby&#8217;s bundler. Clearly, it not only saves the ownCloud team the work of maintaining their own loader but also offers performance improvements! <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/9643\" target=\"_blank\" rel=\"noopener\">Moving completely<\/a> to the Composer loader is already on the <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13241#issuecomment-69469384\" target=\"_blank\" rel=\"noopener\">agenda for ownCloud 8.1<\/a>.<\/p>\n<p>Another change coming in ownCloud 8.1 is <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13227\" target=\"_blank\" rel=\"noopener\">related to memcache<\/a>, something Lukas bumped into when going through code with Blackfire. It is a relatively big change but <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13368\" target=\"_blank\" rel=\"noopener\">there is already code<\/a> and some testing has been done. Due to the impact, however, it will have to wait until the next release.<\/p>\n<h3>Impact on reporting of issues<\/h3>\n<p>Blackfire is also <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13237\" target=\"_blank\" rel=\"noopener\">starting to be used by users<\/a> who report performance issues. When <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13237#issuecomment-69455970\" target=\"_blank\" rel=\"noopener\">asked to run a profiling run<\/a>, the results prompted a <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13269\" target=\"_blank\" rel=\"noopener\">first optimization already<\/a> and <a href=\"https:\/\/github.com\/owncloud\/core\/issues\/13237#issuecomment-69491375\" target=\"_blank\" rel=\"noopener\">more are in the pipeline<\/a>.<\/p>\n<h2>Nice things about Blackfire<\/h2>\n<p>As most of us here at ownCloud work remotely (as in &#8222;not in one city at all&#8220;) this is a nice way to share the results with other contributors. Blackfire makes it really easy to inspect all the calls that are made during a request and to spot bottlenecks in our application even if you didn&#8217;t run the profiler.<\/p>\n<p>It has an easy to use user interface that just works and the profiler has a minimal setup effort. Running an agent, loading a PHP module and clicking on a browser plugin button. That&#8217;s all you need to get some nice graphs with really valuable metrics about your request. Of course we have some wish list items already, like the ability to more easily grab images from the result graphs (or export them to other formats) and a Blackfire Firefox plugin! Last but not least, it would be great if it could do the performance optimizations automatically. For this, integration with Skynet was suggested.<\/p>\n<p>Enthusiasm around the tool is becoming very visible, with a large number of performance related pull requests <a href=\"https:\/\/github.com\/owncloud\/core\/pull\/13511\" target=\"_blank\" rel=\"noopener\">showing up with Blackfire graphs<\/a>. We expect more improvements in ownCloud performance thanks to Blackfire &#8211; a great tool!<\/p>\n<p><em>This post also appeared on the <a href=\"http:\/\/blog.blackfire.io\/owncloud.html\" target=\"_blank\" rel=\"noopener\">Blackfire blog<\/a>. Thanks to Morris Jobke and Lukas Reschke for providing much of the content of this blog. And of course to everybody for the awesome work! If you like to follow ownCloud development, keep an eye on our development reports &#8211; see our <a href=\"https:\/\/owncloud.com\/blog\/owncloud-development-over-december\/\">overview over December<\/a>.<\/em><\/p>\n","protected":false},"excerpt":{"rendered":"<p>A little under two weeks ago, a performance improvement in ownCloud was accompanied by a graph showing the difference in code execution time. The tool used to generate the graph was Blackfire, a powerful and easy to use PHP profiler. Since that first graph, many more have been created and much code has been optimized. [&hellip;]<\/p>\n","protected":false},"author":7,"featured_media":78665,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"_et_pb_use_builder":"","_et_pb_old_content":"","_et_gb_content_width":"","inline_featured_image":false,"footnotes":""},"categories":[342,332,333,335,339],"tags":[],"class_list":["post-7752","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-cloud","category-coding","category-community","category-development","category-owncloud"],"acf":[],"_links":{"self":[{"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/posts\/7752","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/users\/7"}],"replies":[{"embeddable":true,"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/comments?post=7752"}],"version-history":[{"count":0,"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/posts\/7752\/revisions"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/media\/78665"}],"wp:attachment":[{"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/media?parent=7752"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/categories?post=7752"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/owncloud.com\/de\/wp-json\/wp\/v2\/tags?post=7752"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}