App Engine - Cloud SQL Delay

[Carl Smith]

Over the past couple of weeks we have had increase page load times on our website and while running certain pages on our AppEngine setup.

The problem comes when doing anything with the Cloud SQL Database from AppEngine.

We have narrowed down the problem by running the following test

Run the same PHP page on both Compute Engine (via Cloud SQL Proxy) and AppEngine

Result (Compute Engine)

 1539768438.6956 :: Starting...

 1539768438.6960 :: Set order xxxx-xxxxxx-xxxxxx-xxxxxxx as printed

 1539768438.6960 :: - Updating cbd 

 1539768438.7148 :: - Updating printing_flag

 1539768438.7165 :: - Done

Speed: 0.02 Seconds

Result (AppEngine)

 1539768392.9724 :: Starting...

 1539768392.9725 :: Set order xxxx-xxxxxx-xxxxxx-xxxxxxx as printed

 1539768392.9726 :: - Updating cbd

 1539768393.1558 :: - Updating printing_flag

 1539768393.2043 :: - Done

Speed: 0.18 Seconds

The "Updating printing_flag" section is attempting to delete an entry that does not exist, in a table that has less than 200 rows in it, and this on AppEngine is still taking a lot of time compared to Compute Engine.

PHP Page:

addLog('Starting');

//Loop
 addLog('Set order ' . $o->basket_id . ' as printed');

 // Do the setting of this basket when we want it to be saved

 addLog('- Updating cbd');

 db_q("UPDATE cust_basket_detail SET basket_printed = '".date('Y-m-d H:i:s')."' WHERE basket_id = '".addslashes($o->basket_id)."' LIMIT 1"); // [130,000 Rows]

 addLog('- Updating printing_flag');

 db_q("DELETE FROM printing_flag WHERE basket_id = '" . addslashes($o->basket_id) . "' LIMIT 1"); // [200 Rows]

addLog('- Done');

These timings used to be identical until a couple of weeks ago.

There is no load on the AppEngine instance as this is a new version freshly built, and the page loaded a few times with the same result.

[Attila-Mihaly Balazs]

Has the number of requests changed (ie. increased)? (you say this is a new version, but I assume that the public/production version is also accessing the same CloudSQL instance, so increase in traffic there can affect the results).

If you look at the CPU usage, queries per second and read/write operations graphs in the Cloud Console for the CloudSQL instance - does anything stand out? Do you see an increase? (unfortunately it only has data for the last 30 days)

Attila

[Carl Smith]

Hi Attila

I have looked at the graphs on the AppEngine dashboard and it shows that the requests have decreased (possible GoogleBot crawling less because of page load speed), whereas the latency has increased. 

This seems to have happened on or around the 3rd October, but we have not made any changes to the code that connects to the database around this time.

I have opened a issue on Issue Tracker 

Thanks,

Carl

[Carl Smith]

Sorry, the images did not attached

Requests Past 30 Days

Latency Past 30 Days

[Olu]

You have followed the appropriate approach opening the Issue link, as it would be easier to further evaluate the issue from there. Further evaluation of this issue would require reviewing your Stackdriver logs to understand the processes taking place while the request to the Cloud SQL instance is being completed.

[Attila-Mihaly Balazs]

Thanks Carl for those graphs.

Just from the latency graph I would say that there are some very slow requests (because 95th percentile is 0.5 second but the 99th percentile is over 7 seconds) and that the change seems to have occurred on the 3rd of October.

Now, because we're suspecting the CloudSQL server to be the bottleneck, can you look at it in the Cloud Console? (https://console.cloud.google.com/sql/instances). Probably the most useful graphs would be the "CPU utilization", "Read/write operations" and "MySQL queries" for the last 30 days.

I also found it useful to look at the running queries using something like mytop (https://www.tecmint.com/mysql-performance-monitoring/) or just doing "SHOW FULL PROCESSLIST" repeatedly.

All the best,

Attila

[Carl Smith]

Hi Attila

I do not think that the Cloud SQL server is the bottleneck as Compute Engine connects to Cloud SQL perfectly fine, it is just that something might have changed on AppEngine environment around 3-8th October that has caused a slow down.

Here are the graphs for Cloud SQL over the past 30 days

The issue has been escalated to the Cloud SQL team for them to look into this.