0

I'm working on a Symfony2 project that is experiencing a slow load time for one particular page. The page in question does run a pretty large query that includes 16 joins, and I was expecting that to be the culprit. And maybe it is, and I am just struggling to interpret the figures in the debug toolbar properly. Here are the basic stats:

  • Peak Memory: 15.2 MB
  • Database Queries: 2
  • Initialization Time: 6ms
  • Render Time: 19ms
  • Query Time: 490.57 ms
  • TOTAL TIME: 21530 ms

I get the same basic results, more or less, in three different environments:

  1. php 5.4.43 + Symfony 2.3
  2. php 5.4.43 + Symfony 2.8
  3. php 5.6.11 + Symfony 2.8

Given that the initialization + query + render time is nowhere near the TOTAL TIME figure, I'm wondering what else comes into play, and other method I could go about identifying the bottle neck. Currently, the query is set up to pull ->getQuery()->getResult(). From what I've read, this can present huge overhead, as returning full result objects means that each of the X objects needs to be hydrated. (For the sake of context, we are talking about less than 50 top-level/parent objects in this case). Consequently, many folks suggest using ->getQuery()->getArrayResult() instead, to return simple arrays as opposed to hydrated objects to drastically reduce the overhead. This sounded reasonable enough to me so, despite it requiring some template changes in order for the page to render the alternate type of result, I gave it a shot. It did reduce the TOTAL TIME, but by a generally unnoticeable amount (reducing from 21530ms to 20670 ms).

I have been playing with Docker as well, and decided to spin up a minimal docker environment that uses the original getResult() query in Symfony 2.8 code running on php 7. This environment is using the internal php webserver, as opposed to Apache, and I am not sure if that should/could have any affect. While the page load is still slow, it seems to be markedly improved on php 7. The other interesting part is that, while the TOTAL TIME was reduced a good deal, most of the other developer toolbar figured went up:

  • Peak Memory: 235.9 MB
  • Queries: 2
  • Initialization Time: 6 ms
  • Render Time: 53 ms
  • Query Time: 2015 ms
  • TOTAL TIME: 7584 ms

So, the page loads on php 7 in 35% of the amount of time that it takes to load on php 5.4/5.6. This is good to know, and provides a compelling argument for why we should upgrade. That being said, I am still interested in figuring out what are the common factors that explain large discrepancies between TOTAL TIME and the sum of [initialization time + query time + render time]. I'm guessing that I shouldn't expect these numbers to line up exactly, but I notice that, while still off, they are significantly closer in the php 7 Docker environment than they are in the php 5.4/5.6 environments.

For the sake of clarity, the docker container naturally spins up with a php.ini memory_limit setting of -1. The other environments were using 256M, and I even dialed that up to 1024M, but saw no noticeable change in performance, and the "Peak Memory" figure stayed low. I tried re-creating the Docker environment with 1024M and also did not notice a difference there.

Thanks in advance for any advice.

EDIT I've tested loading the page via the php 5.6 / Symfony 2.8 environment via php's internal webserver, and it loads in about half the time. Still not as good a php 7 + internal server, but at least it gives me a solid lead that something about with my Apache setup is at least significantly related (though not necessarily the sole culprit). Any/all advice/suggestions welcome!

Jason Roman
  • 8,146
  • 10
  • 35
  • 40
94638857
  • 111
  • 9
  • there are many things to consider. Are you running this in `dev` environment? If you run that query directly in command line, whats the execution time? What happens if you run this query in a controller, isolated from everything else (templating, twig, etc)? If you divide your problem into smaller sets, it is easier to find out what causes it. – Muhammed Mar 07 '16 at 18:44
  • Thanks for the feedback. Yes I am accessing the page via a browser through Symfony's "Dev" access point (app_dev.php). To be honest, I am not that concerned about the query itself. The toolbar in all environments suggest that the query is taking anywhere from .5 to 2 seconds (according to the toolbar figures, it takes less time on php 5.4/5.6 than php 7, but other factors could be at play). What I'm more interested to figure out is, after spending 1-2 seconds initializing/querying/rendering, what else is going on to stretch the page load out another 5-18 seconds? – 94638857 Mar 07 '16 at 19:06
  • did you try in prod environment? how fast it does there? There are a lot of things in prod that aren't optimized. – Muhammed Mar 07 '16 at 19:08
  • Good question. Since the toolbar does not show in prod, I have to measure the load time by hand. That being said, I've done a few quick tests across all 3 environments using the prod access point, and my load times are virtually the same. They are in the exact ranges that I was seeing via the figures provided by the developer toolbar in DEV for the various environments. – 94638857 Mar 07 '16 at 19:15
  • 21 seconds for page to load is way to much, something ugly is going on there. You said query time is negligible? Try manually checking your code line by line, start with empty action(), then include 'lines' gradually, see where is your breaking point. You should be able to pinpoint the bottleneck for your code. – Muhammed Mar 07 '16 at 19:18
  • I can give that a shot, but the code is really minimal/simple here. 1) hit controller method, 2) run big repository query method with 16 joins, 3) pass result to twig template to render. – 94638857 Mar 07 '16 at 19:22
  • if its that simple there should be no big execution time. Might it be your mysql doing weird stuff, like dns hostname lookup? Maybe try with `skip-name-resolve` in my.cnf for mysql, I've seen where at times not having this option in mysql would lag it badly. – Muhammed Mar 07 '16 at 19:24
  • I'll look into the mysql config you mentioned. I suspect something like this is the culprit. Here are some interesting results though. I reduce the template to a simple

    statement, and load time is not noticeably reduced. So there is no template overhead. I remove all code on the controller other than the repository/query call, and load time is not noticeably reduced. So there is no significant business logic overhead. If I remove the repository/query call, however, it loads instantly. So why does the toolbar show query time of 500ms when in reality its more like 20000ms?

     – 94638857 Mar 07 '16 at 19:33
  • Idk. Read this? https://www.slideshare.net/mobile/marcinchwedziak/effective-doctrine2-performance-tips-for-symfony2-developers-33907944 – Muhammed Mar 07 '16 at 19:44
  • Thanks I'll give it a look. – 94638857 Mar 07 '16 at 20:02
  • It's not the main Q, but I'd like to comment on one aspect: The increased memory usage on PHP 7 (240MB vs 15MB) is likely no actual increase -- the majority of that memory usage simply wasn't counted previously (parts of mysqlnd used the system allocator, we don't track that usage). To see the actual memory usage, look at numbers provided by the OS (e.g. via top). As to the main question: Did you try profiling with XDebug? – NikiC Mar 08 '16 at 00:01
  • Thanks for the feedback @NikiC, that's kind of what I was expecting on that front, but I welcome this exact type of feedback. I want to have a better understanding of all of these figures and how they relate, even if it doesn't answer my main Q. I have not tried XDebug yet, but might set it up. There is obviously query inefficiency involved, a little bit of php5x inefficiency, but the major bottleneck, as noted by my comment two comments ago, the major bottle neck appears to be Apache. When I serve the page through internal php webserver, it loads in half the time. Need to test nginx. – 94638857 Mar 08 '16 at 17:56

0 Answers0