5

A friend and I just started working in a project which other people stopped developing a couple of years ago, and we're trying to resurrect it. We've already solved most of the setup-related issues, but there's a really annoying one that we can't figure out.

In our localhosts, all the pages take A LOT of time to load/refresh. And I don't mean assets, scripts or anything, the problem is the latency until the first request completes. Most times it takes 15 to 30 seconds, which is unacceptable, and sometimes it even goes up to 1 or 2 minutes.

For example, here's a screenshot of the Network tab in Chrome dev tools. The first row is the view, the other ones are assets.

Example of crazy latency


We've googled for hours and tried a few different things, but none of them has worked. Some solutions like this one point to some Apache's httpd.conf settings, but I discarded that since I'm using the same server for other projects and this never happened (I tried it anyway, but didn't work). Others point to PHP version conflicts, so I tried changing the PHP in my MAMP from 5.4.10 to 5.2.17 (the project requires 5.2.3+), but that didn't seem to work either.

Apart from my MAMP installation, we also tested it in a Windows machine with WAMP (PHP5.5), and also in another Mac with a clean MAMP (PHP5.5), and the same thing happens in both environments. So, we are now wondering if the problem could be in CodeIgniter itself (which sounds unlikely) or in some project configuration, but we're pretty new to CodeIgniter (and also not PHP experts) and couldn't find anything.

Oh, and we also tried contacting the original developers, but they said that was two years ago and sounded like they're unwilling to help. I really hope they didn't have this issue while developing the project back then, because working with 30sec load times it's just insane.

Someone have any idea or know about something more we could try to find the issue? I could post some code if needed.



Update: I just found this unsolved question where a user experienced a similar issue with Laravel, but only sometimes. As I said, in my case this happens always, with latency times spanning from ~10 seconds to a few minutes.



Update 2: As suggested by Wrikken, i ran it through an xdebug profiler, but I'm not sure of how to interpret the results to see where the issue is. I opened a snapshot with PHPStorm's "Analyze Xdebug Profiler" tool, and sorted it by time used in each call. Here are a couple of screenshots:

Execution Statistics tab Call Tree tab

And sorted by Own Time:

Sorted by Own Time

That CashewModel showing up in some lines is a some sort of custom library built by the previous developers, which was also causing some problems we already solved. I hope the problem isn't hidden there, because I have no idea of how most of that custom code works.

Any ideas? Again, I can post code if needed.



Update 3: Digging into the code, that MY_Controller in the screenshot above is a file where the previous developers created some custom controllers extending CI_Controller. I just found out that they pushed all the Cashew code to GitHub, here's the MY_Controller file.

I'll also paste here all the relevant code around line 467 (in GitHub's version is 464), which involves the _remap function inside the CashewController and is where the profiler says all the time is spent. I translated some comments and names into English.

/**
 *
 * Extension of the default controller, adding support for templates
 * 
 * Usage example:
 *
 * class Dummy extends EC_Controller
 * {
 *     public function index()
 *     {
 *         $this->add_section('id_in_template', 'page_name');
 *         $this->render_page(); // Renders the default template.
 *     }
 * }
 *
 */
class CashewController extends CI_Controller
{
    //
    // Some attributes here
    //

    function __construct() { ... }

    /**
     * We use this _remap to automatically create the CRUD method calls
     *
     * @param string $method
     * @param string $params
     */
    public function _remap($method, $params = array())
    {
        // NEW
        if ($method == 'new') {
            $method = '_new';
        }
        // CREATE
        else if ($method == 'index' && $this->request_method() == 'post') {
            $method = '_create';
        }
        else if (is_numeric($method) && $this->request_method() == 'post' && count($params) == 0) {
            $params[0] = $method;
            $method = '_create';
        }
        // SHOW
        else if (is_numeric($method) && count($params) == 0) {
            $params[0] = $method;
            $method = '_show';
        }
        else if (is_numeric($method) && count($params) == 1 && $params[0] == 'edit') {
            // EDIT
            if ($this->request_method() == 'get') {
                $params[0] = $method;
                $method = '_edit';
            }
            // UPDATE
            else if ($this->request_method() == 'post') {
                $params[0] = $method;
                $method = '_update';
            }
        }
        // DELETE
        else if (is_numeric($method) && count($params) == 1 && $params[0] == 'delete') {
            $params[0] = $method;
            $method = '_delete';
        }

        if (method_exists($this, $method)) {
            return call_user_func_array(array($this, $method), $params);
        }
        show_404();
    }

    //
    // Some more functions
    //
}


So something's happening inside that call_user_func_array(array($this, $method), $params), right?

Community
  • 1
  • 1
seiseises
  • 450
  • 2
  • 12
  • Please edit your question and include a [MCVE](http://stackoverflow.com/help/mcve), that is the least amount of code that's required to reproduce the issue. –  Sep 10 '14 at 00:59
  • I usually try to do that, but as I stated in the question I'm not even sure where the issue comes from, so I don't know what parts of the code I should post. If someome could gave me any hint, I'd be glad to post it. – seiseises Sep 10 '14 at 01:05
  • Run it through an xdebug profiler, and you'll have your answer probably. – Wrikken Sep 10 '14 at 01:33
  • is it slow when you try to access an empty controller with no code in it? – Patrick Sep 10 '14 at 07:12
  • @Wrikken I just updated my answer with xdebug information. – seiseises Sep 10 '14 at 10:50
  • @Patrick I didn't test that yet, but it's slow in every page, even the very simple ones. I'll try to test what you say, though as I said I'm new to CI so I need to learn how it works first. – seiseises Sep 10 '14 at 10:54
  • I see that you're using "MY_Controller", that's a custom controller, it might have some heavy load running on it. check it out aswell. – Patrick Sep 10 '14 at 11:26
  • Try to use memcache and see it will effect latency also try to look in js,css,images related loadings on server maybe to look into .htaccess as well. What happens when you disable css,images? – AHashmi Sep 10 '14 at 11:41
  • @Patrick Yes, it's a file that defines some custom controllers, all extending from CI_Controller. I added another update with the potentially relevant code. – seiseises Sep 10 '14 at 13:30
  • 1
    5k queries for a frontpage load.... That smells like a problem, and possibly a design flaw... – Wrikken Sep 10 '14 at 16:35
  • @Wrikken Yes, there are a lot of flaws in both the architecture and the frontend and a lot of room for improvements and optimization, that's what we have inherited and that's our task to improve. But obviously we need to solve this issue first, because is too blocking to continue doing all the other things. – seiseises Sep 10 '14 at 18:08
  • OK, well, rather the sorting on time, sort on "own time" (cumulative) time, those are the actual calls that are either taking long (low count, high own time), or are excessively used (high count, high time). You are seeing that 'all' time is spent at that line 467 (/ 464), because that is the one doing the actual entire request, with probably a quite deep tree of function calls behind it. So, don't look at that one: what it does deeper on is the issue. – Wrikken Sep 10 '14 at 18:15
  • @Wrikken Ok, I added the screenshot below the other two. Does that really mean that database queries are consuming 41% of the time? I knew the code was far from optimal, but that sounds like this is much worse than I thought. – seiseises Sep 10 '14 at 18:49
  • Seems that way. Taking the function namens into account I would guess this is a very poorly written "menu creation function", which executes DB queries in a recursion or loop. – Ulrich Thomas Gabor Sep 10 '14 at 18:55
  • @GhostGambler Ok, so I get we definitely need to rewrite the whole app at some point. However, I still can't understand how all this backend code takes THAT long to run, and especially why that time changes that much from one execution to another. I mean, I would understand a bad backend taking maybe 10 seconds... but 2 minutes for the next refresh? Don't you think there must be something else going on? – seiseises Sep 10 '14 at 19:53
  • 1
    Seems queries are a bit factor indeed (if it's building a recursive many of some sort, you [can do it far quicker with one query and build in application](http://stackoverflow.com/questions/13888389/mysql-parent-child-same-table-php-nest-children-within-parents-as-a-multidimens/13888486#13888486)), but hard to say without the full code (which would be out of scope on SO here). And 140k calls to preg_match... Anyways, I would hazard the guess that CashewModel is poorly written / scalable, but then again I don't know what kind of data it tries to show on this page. – Wrikken Sep 10 '14 at 20:03
  • 1
    BTW: your queries aren't slow, they average 4ms each, it's the number of them. However: does the CashewCache work properly? Otherwise, if I [look at the model](https://github.com/cubledesarrollo/cashew/blob/e0da464b6c9dd40c8d0d7d2453275178eb72f733/application/core/MY_Model.php#L153), it's a lot of extra queries. In other words: a heavy relying on Memcached here. Do you have that extension enabled, and does `$this->CI->config->item('memcached_servers');` contain reachable memcached servers? – Wrikken Sep 10 '14 at 20:14
  • @Wrikken If it helps, I can say it's a website for buying and selling second-hand articles, with users, articles, categories, authentication and all the usual stuff. This particular case was the main page for logged users, which shows a list of articles that the user might want. But as I said, these issue happens even in the simple text-only pages like FAQ or About. I just tried with the FAQs and it took 48 seconds to start loading. Then clicked refresh, and 2.2 minutes. It's crazy. – seiseises Sep 10 '14 at 20:20
  • @Wrikken I don't know about the memcached servers, it could be something about them. I'll have a look at that and comment here. – seiseises Sep 10 '14 at 20:25
  • @Wrikken I'm so happy right now - **that was it!** Thanks so much, I didn't even know what memcached was, so I didn't know it wasn't installed in my system. I followed the instructions [here](https://github.com/majksner/php-memcached-mamp) and it worked perfectly. There are still some requests taking 10-30 seconds from time to time, but in general the latencies are now between 0.5 and 5 seconds, which is acceptable. Post an answer if you want, and I'll accept it. And thanks everyone for your help, I truly learnt a lot with this :) – seiseises Sep 10 '14 at 22:52

3 Answers3

1

I found the issue thanks to a comment posted above but the user didn't write an answer, so I'm posting it here.

The code written by the previous developers is making a pretty intensive use of the memcached extension, which I never used before, so I didn't know what it was or that I needed to enable it in my computer. I followed the steps here and that was it, load times are acceptable now.

Thanks everyone!

Community
  • 1
  • 1
seiseises
  • 450
  • 2
  • 12
0

That sounds like a timeout on a domain or host-name look-up (or IP reversal), a bad localhost resolve to the IPv6 ::1 (with a fallback to 127.0.0.1), or an HTTPS request that timeouts out when doing a certificate revocation list check (you'd need to remove that option from whatever function that is handling this).

rightstuff
  • 6,412
  • 31
  • 20
  • That's what I first thought, and several answers and solutions to similar questions pointed at that. But I don't have much experience with server-side stuff, could you please elaborate a bit more on what things could I try? I tried changing `localhost` to `127.0.0.1` in the `httpd.conf` file, but it didn't seem to change nothing. I explained that in my question. – seiseises Sep 10 '14 at 17:25
  • @seiseises, it wouldn't necessarily be an Apache configuration issue, unless it's something like having `HostnameLookups on` somewhere in your httpd config files or .htaccess file. I would rather open an editor like Notepad++ and have it search the entire website (all files) on strings `localhost` and your actual domain and host names. Then change all those to `127.0.0.1`. You might also need to install WinDump and see what requests this application makes through TCP/IP. – rightstuff Sep 10 '14 at 18:36
  • I have other working projects in the same server and I think I always always use localhost, so I don't really get why I should specify the 127.0.0.1 here. I did that search though, and it doesn't show up in weird places (I think). I also searched `127.0.0.1`, and it shows up as the `default_host` at `.system/libraries/Cache/drivers/Cache_memcached.php` (with `default_port=11211`); and at `database.sql`, stored as a field inside some demo users. Does any of that look wrong? I tried changing the `127.0.0.1`s to `localhost`s and viceversa, but it didn't seem to work. – seiseises Sep 10 '14 at 19:32
  • 1
    It 95% certain that something is timing out (and that's were I would focus your effort tracking this down). Do you have a memcached server installed and running on the same system? If your app is trying to reach it, that could be an issue. On the other part, "localhost" can sometimes cause issues because 1) there might be weird routing issues especially with IPv6 enabled and 2) some programs re-interpret "localhost" to use sockets or named-pipes instead of TCP/IP. – rightstuff Sep 11 '14 at 20:00
  • You can be 100% sure now, I solved it yesterday after another user pointed at that, it's posted in the comments above. The code was trying to use a memcached server but I didn't have it installed in my system (because I didn't even know what it was). Thanks anyway for your time! :) – seiseises Sep 12 '14 at 00:33
0

I had the same problem. Some of the potential solutions are:
1. You might have debug mode on.
2. The cache might not be setup. Set it to auto cache.

If none of them works out, try using docker for codeigniter which worked out foe me.

Hope it helps.

Rachit
  • 208
  • 4
  • 19