Super slow page loads, simple scaffolding


#1

I’m not new to Cake, but I am working my first 3.0 project.

I’m stumbling quite a bit with page load times. I’m seeing 8 to 9 seconds for 20 rows on a controller index, 30 to 40 seconds for a controller view. The debugger show’s pretty decent connections to the db, not a lot of overhead. I tested all the same queries that the index and view actions make in a test app with super simple PHP, and the speed to execute were all between 700 to 1500 milliseconds (with a half dozen belongsTo and hasMany).

I have nothing special setup, just using bake scaffolding. No extra code, helpers, auth. I get the sense if I did this in Cake 2.0, the pages load time would be 1 to 2 seconds.

I’m just stumped. What could make the controller action take 5 seconds and the corresponding view 3 seconds? Or in the case of the View 45 or more seconds?

I’ve switched php from 5.6 to 7.0. I have other Cake (2.0) apps running on this server and they are lighting fast.

I’m just stumped. I keep thinking their must be some config setting, turn debug off, or something, but nothing seems to make a difference.


#2

Does it have the same timings with debug set to false?

Did you set permisions on logs and tmp folders? Maybe its recreating cache every request.


#3

debug true or false make about 30 milliseconds difference.
logs are being written to, so I assume permission are correct.
tmp folder shows files with current time stamp, so I assume that is correct also

one index function looks like this

function index() {
    
$course = $this->paginate($this->Course); //about 4.5 seconds
    $this->set(compact('course')); //about 3 seconds
    $this->set('_serialize', ['course']);  //about 1 second
}

turning these lines off one by one, i get the approximate timings shown in the comment.

With them all commented out, the page renders in 16ms.

This model has about 12 columns. It is Microsoft SQL Server. So maybe that has something to do with it??? Index takes about 8.5 seconds to return the first 20 rows of a table with 750 rows. It definitely seems to be something in the 3.0 ORM. However, I can’t wrap my head around 3 seconds to compact 20 rows.


#4

So one thing I figured out was the whole regeneration of Schemas on each request. Unfortunately, Schema generation (and the time it takes) isn’t shown in the debug tool / timings. This would be a nice addition I think. After updating my app.php

'cacheMetadata' => true

And turning off +2 minutes in bootstrap.php

if (Configure::read('debug')) {
    //Configure::write('Cache._cake_model_.duration', '+2 minutes');
    //Configure::write('Cache._cake_core_.duration', '+2 minutes');
}

this did help reduce page load times by about half.

However, I’m still running into view render times that are way off.

For example, I select all the rows of a table.

$instructor ->find();

Which produces 130 results in 86ms (per the Timer)

Rendering these results into index.ctp take 20 seconds.

20 seconds to render 130 rows with 6 columns?

The Timer says this is all in the index.ctp, but i don’t quite believe it.

I’ve paired this back to the simplest of foreach statements, removing anything related to pagination.

<tbody>
            <?php foreach ($instructor as $i): ?>
            <tr>
                <td><?= $i->Instructor_Number ?></td>
                <td><?= $i->First_Name . " " . $i->Last_Name ?></td>
                <td><?= $i->Company_Name ?></td>
                <td><?= $i->Office_Phone_Number ?></td>
                <td><?= $i->Specialization ?></td>
                <td><?= $i->Association ?></td>
            </tr>
            <?php endforeach; ?>
        </tbody>

So i realized that foreach in this case isn’t actually iterating over an Array but over a Query object. So, it’s not the view, but the Query that is taking all the time.

Getting back to $instructor.

While it appears to take 86ms to perform the query, adding the following shows that in fact it’s not the view at all but still the query.

$instructorsTable = TableRegistry::get('SomeTable');
$instructor = $instructorsTable ->find()->toArray();
die("Here taking 20 seconds");

The finger is now pointing back at the Table /Query / DataSource.

So, going as low level as I can imagine, while still using Cake functions.

$connection = ConnectionManager::get('default');
$instructor = $connection->execute('SELECT * FROM Instructor');

And this takes 20 seconds.

As an experiment

$this->connection = new PDO ("sqlsrv:Server=$this->hostname;Database=$this->dbname", "$this->username", "$this->pwd");
$statement = $this->connection->prepare(''SELECT * FROM Instructor');
$rows->$statement->fetchAll();

Takes just 242 milliseconds to print_r($rows) back to the screen.

I’m just stumped. I have no idea what manipulations of the data Cake is doing behind the scenes that could warrant taking almost 20 seconds to complete.

I still feel like there is some basic switch I’m missing. Or maybe there is some serious bug with SQL Server Datasource??. I just don’t know.

Thanks again!


#5

Very strange… What version of mysql are you using?

did you enable 'init' => ['SET GLOBAL innodb_stats_on_metadata = 0'], in your app.php ?

EDIT: did not read that you are using SQL server, maybe try another driver?


#6

What version of SQL Server, and the php sql server driver are you using? Do you have xdebug installed/enabled? I remember having horrible sql server performance in the past (This was about 3 years ago), and disabling xdebug solved all the issues.

BTW, the debug kit bar does give you are breakdown of metadata fetching if you open up the SQL panel. It will also show you exactly which queries are taking their time.


#7

Maybe a hardware failure by a faulty drive? Could this be an option? High CPU-Load? VM? Check the memory usage of the sql server. I know, that MSSQL uses a lot of memory if it is not set up to explicitly use a specific amount. Are the Servers (Web and SQL) on different VMs/Machines?

I guess, it is not a cake-related problem.

btw: have you tried moving to php7. I could speed up cakephp by 5 only by switching to php7 with the default values. Not, that this should be the soluting (something is definetly wrong), but a nice hint.


#8

The strange thing is, I don’t think it has anything to do with calling the SQL Server (2016 hosted remotely). The slowness seems to be in the conversion of the raw data returned by SQL into a Collection. If it can be believed, the SQL responses are all in the milliseconds. I’m wondering if it has anything to do with the Inflector, as the tables are not Cake standard names (e.g. “Instructor_ID” rather than “instructor_id”), and never will be as I don’t control the DB.


#9

I’ve narrowed the problem down to the prepare function in Database\Driver\Sqlserver.php.

public function prepare($query)
    {
        $this->connect();
        $options = [PDO::ATTR_CURSOR => PDO::CURSOR_SCROLL];
        $isObject = $query instanceof Query;
        if ($isObject && $query->isBufferedResultsEnabled() === false) {
            $options = [];
        }
        $statement = $this->_connection->prepare($isObject ? $query->sql() : $query, $options);

        return new SqlserverStatement($statement, $this);
    }

It comes down to the cursor options.

'$options = [PDO::ATTR_CURSOR => PDO::CURSOR_SCROLL];

Setting this to

$options = [];

Then any query take less than 100ms, leaving it as it and any query takes a really long time.

The same thing can be achieved by setting this in Database\Query.php

protected $_useBufferedResults = false;

Pagination break and who knows what else, as it seems Collections are built predicated on the assumption that the results set can be interated a number of times, which isn’t the case unless the Cursor Options isn’t set to “CURSOR_SCROLL”.

Now what? Uggg.


#10

I think you should open a issue

just setting $query->enableBufferedResults(false); will disable collections methods


#11

Looks like there is an open bug for this issue:

https://github.com/cakephp/cakephp/issues/8579

The solution is:

$options = [PDO::ATTR_CURSOR => PDO::CURSOR_SCROLL, PDO::SQLSRV_ATTR_CURSOR_SCROLL_TYPE => PDO::SQLSRV_CURSOR_BUFFERED];

Which results in huge performance improvement in my current environment.

Thanks much all who chimed in with assistance.


#12

My guess would be that it is definitely not a cakephp3 problem but a server configuration problem. I would test my application by set up an Amazon instance, to test it. If you follow this tutorial it might help. Let me know if you get stuck. http://www.skillbooker.com/tutorials/cakephp/set_up_an_amazon_ubuntu_ec2_instance_with_mysql_php_apache_and_phpmyadmin_-_on_windows_cakephp3

Regards