Skip to main content ↑ ↓
Intermittent Loading Slowdowns Started by Ant59 · · Read 12080 times 0 Members and 1 Guest are viewing this topic. previous topic - next topic

Intermittent Loading Slowdowns

I've been having problems with intermittent huge loading times for my Elkarte forum. I host other sites on the same Nginx server, which are not affected, so it doesn't seem to be a Nginx/PHP/MySQL problem. As far as I can tell, it's Elkarte's doing.

Every few requests, when I've not made request for at least 30 seconds, the next request will take upwards of 5s to load. This doesn't happen every request - most are less than 200ms with SPDY.

I've screenshotted the output of PHP-FPM's "slowlog" below and a waterfall of the page load from Firebug.



I'm hoping someone might be able to shed some light on this, as to whether these Elkarte functions are to blame or whether it's a server issue of some sort. I can provide as much information as needed.

Re: Intermittent Loading Slowdowns

Reply #1 –

For "random" slowdowns I may think of two reasons:
1) a new caching of styles and scripts (javascripts),
2) a new caching of hostname lookups.

From the screen you are posting looks like the hostname lookup.
It's a bit strange the 30 seconds because the hostnames should be stored for 600 seconds, but... it may also be you are not using cache and it relies maybe on some server-side caching of the DNS record.

You may disable the hostname lookup in admin > config > server > general.
Bugs creator.
Features destroyer.
Template killer.

Re: Intermittent Loading Slowdowns

Reply #2 –

Quote from: emanuele – You may disable the hostname lookup in admin > config > server > general.

I've disabled hostname lookup, and I'll see whether it makes a difference or not over the next hour or so. Thanks.

Re: Intermittent Loading Slowdowns

Reply #3 –

I see the same problem actually.  Hostname lookup has been disabled and just a pretty simple Apache setup.

If I haven't done a particular request for a while it takes about 4 to 5 seconds to generate the page according to Elk's own page load time output.  After that it goes back to about 0.03 seconds until some unknown timeout or something.

Re: Intermittent Loading Slowdowns

Reply #4 –

Yes, that's exactly what I'm getting. I'm on Nginx, so it seems it's definitely an Elk issue.

I've not been seeing the issue since having disable hostname lookup, but I'll continue testing.
Last Edit: November 10, 2014, 07:57:37 am by ant59

Re: Intermittent Loading Slowdowns

Reply #5 –

If you are not on a live setup[1] you can add to your Settings.php the following line to try to get more info:
Code: [Select]
$db_show_debug = true;
it will output more debug info at the end of the page with also queries execution time and the time at which each query has been executed.

It happens to any account, or maybe just with admins?
1 Well, you could use it live as well, but it's not really so nice to see and may in certain circumstances reveal full file paths.↵
Bugs creator.
Features destroyer.
Template killer.

Re: Intermittent Loading Slowdowns

Reply #6 –

I'm live and an admin.  It is not restricted to admin pages though.  I've seen it on post, who, and unread frequently.

Re: Intermittent Loading Slowdowns

Reply #7 –

And sadly it's not readily repeatable for me.  I can't just not view a page for five minutes and know it will be slow every time.
 

Re: Intermittent Loading Slowdowns

Reply #8 –

Quote from: emanuele –
Code: [Select]
$db_show_debug = true;

Testing now. Throws up a lot of information. I'll keep my eye on CPU time when I get a random slow load.

Re: Intermittent Loading Slowdowns

Reply #9 –

What I'm trying to do is identify a more or less common pattern. For example, admins have some "security checks" done while loading the page (actually we should really do them randomly I think, it's useless to check Settings.php~ at each and every page load), so this may be a problem. Or maybe it happens only to registered members, because... dunno, maybe some ban check.

@ant59 another interesting and potentially useful is to see into "show queries" when the "time into the request" jumps. Usually the times have very small differences from the following one, but is something messes with timing and slows down something, you will notice the "jump" in time between two different queries (for example query 1 "which took 0.0002 seconds at 0.07130003 into request." and query 2 "which took 0.0003 seconds at 3.5 into request.").

Also if you have disabled the hostname look up (that based on the screen you posted before was the problem due to gethostbyaddr), have a look again at the PHP-FPM's "slowlog", it may give some more insights. ;)
Bugs creator.
Features destroyer.
Template killer.

Re: Intermittent Loading Slowdowns

Reply #10 –

Refreshing it with "Show queries" open now. I've turned hostname lookup back on, but I'm having trouble replicating the issue now. It's super-weird because this issue has been happening for weeks, but now I can't reproduce it. PHP-FPM's slowlog isn't showing anything either now :S I even ran a long test with Seige on 1 concurrent user and not a single peak over 1 second after about 5 minutes running.

I'll keep going. I've not done anything I can think of that would have fixed it.

Re: Intermittent Loading Slowdowns

Reply #11 –

I've seen this problem basically since installing elk beta.  It's very random.  I'm sure it will show up again.

Ema is there a timeout on the css/js cache that will cause it to redo them even if they haven't changed?

Re: Intermittent Loading Slowdowns

Reply #12 –

I understand the issue now. Elkarte is failing to find my hostname using the host or nslookup commands on the system, and is falling back to the PHP function "gethostbyaddr()" which is extremely slow. It finds many users' hostnames fine though, which is why none of my testers have come across it. Seems if you're using a common ISP, it has no problem.

I've simply completely disabled hostname requests from the admin panel. I can't think of any functionality that I lose?

Re: Intermittent Loading Slowdowns

Reply #13 –

Can confirm my findings: Just ran a -c10 -r10 siege test against my site with hostname requests off and not a single request showed up in PHP-FPM's slowlog.

Code: [Select]
Transactions:		         100 hits
Availability:		      100.00 %
Elapsed time:		       26.05 secs
Data transferred:	        3.39 MB
Response time:		        1.84 secs
Transaction rate:	        3.84 trans/sec
Throughput:		        0.13 MB/sec
Concurrency:		        7.05
Successful transactions:         100
Failed transactions:	           0
Longest transaction:	       1.31
Shortest transaction:	        0.43

Re: Intermittent Loading Slowdowns

Reply #14 –

Quote from: scripple – Ema is there a timeout on the css/js cache that will cause it to redo them even if they haven't changed?
Not that I can see:
https://github.com/elkarte/Elkarte/blob/v1.0.1/sources/SiteCombiner.class.php#L284
only if _isStale returns true a new compilation is prepared.
Bugs creator.
Features destroyer.
Template killer.