First byte - analysis

[Adlago]

In this topic, @ASTRAPI made a detailed description of what is and what the first byte contains, for which I thank him.

 

For a few months now, I've been doing a lot of first byte analysis and testing in my installation.
Here are the results I get - pay attention, these results are when tested with a Chrome browser developer tool and I only look at the waiting time, ie. real time in which the server started to work after request, and produces source code.

Sorted as my stats, the results (probably over 1000 test) look like this:

70% - waiting time in the interval 90 - 150 ms

20% - waiting time in the interval 150- 400 ms

8% - waiting time in the interval 400- 1000 ms

2% - waiting time in the interval over 1 second, often over 2 seconds

I created a ticket for my host company because my host plan is expensive and with good parameters guaranteed.
The guys from the host company have done more than 24 hours of analysis and here's what they found

Below I post their response.

======================

In one of the many checks that it develops, we notice that "sleep" during loading and run all that are generating source code scripts. To look at the sleep effect of the application, apply a sample of the command that checks all file calls (at system level) during site loading:

16:03:15.969084 open("/home/database/public_html/system/Session/Front.php", O_RDONLY) = 4
16:03:15.970734 open("/home/database/public_html/system/Session/Session.php", O_RDONLY) = 4
16:03:15.971749 open("/home/database/public_html/system/Theme/Theme.php", O_RDONLY) = 4
16:03:16.983086 open("/home/database/public_html/system/Node/Model.php", O_RDONLY) = 4

After executing the /home/database/public_html/system/Theme/Theme.php file, we see that it is almost a second before the next script is loaded and /home/database/public_html/system/Node/Model.php. For more precision, we see that Theme.php started its implementation at 16: 03: 15.971749, and a second later, at 16: 03: 16.983086, the Model.php implementation started. This second delay is due to the following snippet of Theme.php code:

/* If we don't have a compiled template, do that now */
if ( ! $cachedObject and !isset( \IPS\Data\Store::i()->$key ) )
{
/* It can take a few seconds for templates to finish compiling if initiated elsewhere, so let's try a few times sleeping 1 second between attempts
to give the compilation time to finish */
$attempts = 0;
while( $attempts < 6 )
{
if ( $attempts === 5 )
{
/* Rebuild in progress */
\IPS\Log::debug( "Template store key: {$key} rebuilding and requested again ({$app}, {$location}, {$group})", "template_store_building" );

/* Since we can't do anything else, this ends up just being an uncaught exception - show the error page right away to avoid the unnecessary logging */
\IPS\IPS::genericExceptionPage();
}

$built = $this->compileTemplates( $app, $location, $group );

if ( $built === NULL )
{
$attempts++;
sleep(1);
}
else
{
break;
}
}

/* Still no key? */
if ( ! isset( \IPS\Data\Store::i()->$key ) )
{
\IPS\Log::log( "Template store key: {$key} missing ({$app}, {$location}, {$group})", "template_store_missing" );

throw new \ErrorException( 'template_store_missing' );
}
}

This part of the code checks whether a compiled template is already available and if not, compiles. Several attempts are made in the compilation process, which according to the code comment may take a few seconds. In our opinion, the presence of sleep (1) is the specific reason for the delay sometimes occurring.

For our part, we might recommend that you consult the developers who assisted with the site's construction. From our many attempts to reproduce the delay, we see that to a large extent the site is well optimized, but rebuilding templates is a functionality that needs to be discussed with developers.

In our view, this part of the code is the reason for the TTFB indicator's unconscious state, since it directly depends on the time it takes to process all the functionality involved in generating the source code.

==================================

Whether these guys from the analysis department of my host company are right - I don't know.
I share it here and look forward to clarification.
Thanks.

 

[Matt]

Templates should only compile once after either upgrading, or clearing all datastores (which won't happen many times if at all in normal use). When templates rebuild, 99% of the time they rebuild on the first go without needing the attempts loop and sleep. That is there to catch the 1% of times that some random event on the server means the templates weren't compiled properly (possibly because a previous attempt has a lock on the template rebuild). The sleep just pauses for 1 second to allow the lock to be lifted by another process.

So in short, that sleep should only very rarely be hit and won't be run on every single page load.

That is the only time we deliberately add a sleep() call.

As for the loading of the PHP files, I have no idea why there would be any latency but using a compiler like OPcache should negate that.

[Adlago]

thanks
I have sent your reply to my host.
If they have more questions, I'll add to this topic.

[Adlago]

On 12/23/2019 at 1:46 PM, Matt said:

As for the loading of the PHP files, I have no idea why there would be any latency but using a compiler like OPcache should negate that.

I have Opcache turned on. These are all PHP modules included.

But my host replied that there was no reason other than that already stated.

Does it make sense for your research to I create a ticket?
This first-byte variable behavior started with me after May - I don't remember which version it was before - but I used this host packet more than 5 months ago - and there was no problem with the first byte.
Or any idea what I should change?

[Adlago]

Now I've tested your site - the same first byte behavior - from several tests in 5 minutes, and in your site the first byte changes in the interval from 50 to over 800 ms.
And it is a waiting time.
You use CDN, I'm only Apache - but this first-byte behavior is the same, ie. you have some bug in the source code software.

See test screenshots

 

[Adlago]

I have more test observations - but with Christmas calm in the forum, it's a weird 900 ms waiting time ...

[Adlago]

On 12/23/2019 at 1:46 PM, Matt said:

So in short, that sleep should only very rarely be hit and won't be run on every single page load.

Please check the whole logic for this.
More than 2 hours - I changed sleep from 1 second to 100 ms using usleep.
More than 95% of my first byte (waiting time) are excellent - 90-140 ms, in other cases they are from 200 to 500 ms.
Probably the logic of what you say does not work of plan.

[ASTRAPI]

Yes it will be great if there is another way to do that or be able to improve the current code for this 🙂

[sadams101]

I've had constant TTFB issues with IPB4 which I've never been able to solve using any caching method, and I've tried them all. Although I am not a coder, I have suspected that there is a delay somewhere in how your code loads, and this delay can be replicated on other boards I've tested. I certainly hope you can look into this further, given the huge effect it has on everyone who uses the software.

[bfarber]

I've made a note for us to review this area of code for 4.5.

[bfarber]

I added debug logging to our company forums here, and another employee added it to his personal live site. In both cases, we are not seeing this area of code you reference (the sleep() call in Theme.php) hit unless we actually intentionally clear the datastore (i.e. run the support tool).

The sleep() call here is only hit if templates need to be rebuilt, and they are actively being rebuilt by another request - i.e. you have cleared the datastore and two users are hitting the page at the exact same time. The sleep is purely designed to let the second request that comes in wait a second (up to 5 seconds) for the rebuild initiated by the first request to complete. It should effectively never be hit regularly on a site.

I would recommend submitting a ticket if you believe this is being hit regularly on your installation. It's possible the code is a red herring and was simply identified by your host during a code sweep looking for the problem, or it's possible you're using some sort of customization that is clearing your caches routinely which is leading to this problem. I can't really say from here right now, just that I am not seeing problems with this sleep call both here and with another site we added logging to.

[TSP]

Do people affected here by any chance have multiple memcache-servers defined? 

I'm currently investigating some issues related to a lot of INSERT INTO core_store-queries with the same values being generated. One of the instances where this happens seems to be when one or multiple of the memcache-instances is unavailable. 

[Adlago]

@bfarberThese are the tests for your site from the Chrome browser console. 5 tests every minute.
How will you explain this wide range of waiting times? This is observed in all sites using version 4.4.x - a large range of waiting time - you use the CDN and it happens again. Other sites use the one server - no matter Apache or Nginx- the results are the same, great waiting time game ...
There is some mistake, I think, when creating an html file , what is it I don't know.

Edited January 9, 2020 by Adlago

[bfarber]

All but one of those screenshots show a TTFB below 500ms, which is an acceptable range. The software does have to process things after all - we're not working with static HTML files where Apache can simply spit the file contents out to the browser.

The 600ms TTFB seems to be an outlier.

That said, ALL of these are below 1 second (1000ms), so the Theme.php code would not be relevant. The response would have to be longer than one second for the sleep call you highlighted to have possibly been hit.

[Adlago]

19 minutes ago, bfarber said:

All but one of those screenshots show a TTFB below 500ms, which is an acceptable range. The software does have to process things after all - we're not working with static HTML files where Apache can simply spit the file contents out to the browser.

The 600ms TTFB seems to be an outlier.

That said, ALL of these are below 1 second (1000ms), so the Theme.php code would not be relevant. The response would have to be longer than one second for the sleep call you highlighted to have possibly been hit.

For a sleep -this is the opinion of my host company. There may be another reason.
In the last hour I have screenshots from tests on this site with over 1 second waiting time. If you want I will post them. Although you too can get such results.
In these cases, the distance from the client to the server does not matter, because the time we are discussing is the running time of the server after it is connected for create html.
I will repeat myself again - in the process of producing html there is some problem - it is not correct to have such a wide range for waiting time.
And what causes this - I would be glad to know, but since May 2019 I have not found one yet. In the previous version before May 2019, there was no such ripple of this waiting time ...

[bfarber]

3 hours ago, Adlago said:

I will repeat myself again - in the process of producing html there is some problem - it is not correct to have such a wide range for waiting time.

What makes you say there shouldn't be a range?

Some pages we may have to rebuild sidebar blocks because a cache has become out of date, and some pages we may be able to pull from cache. Some page loads we may have to update the session, while some page loads we may not. There are definitely going to be various factors that affect the page load time, and absent evidence of a specific issue, the statements here are a bit broad to act on. Hence why I recommended submitting a ticket.

[Adlago]

30 minutes ago, bfarber said:

Some pages we may have to rebuild sidebar blocks because a cache has become out of date,

In my site I use cache block time of 16 minutes. In 16 minutes I do more than 10 tests as above - all tests are in the range of 90 - 900 ms. Ie this cache is unaffected.

33 minutes ago, bfarber said:

and some pages we may be able to pull from cache.

I do not use the guest cache page - ie. and this does not affect me in the test.

35 minutes ago, bfarber said:

Some page loads we may have to update the session, while some page loads we may not.

If this happens within the 10 minute test interval - for a test every minute, then only one of the tests will be affected. But this is not observed. Ie this is not the reason for the unclear game of waiting time.

39 minutes ago, bfarber said:

Hence why I recommended submitting a ticket.

If this game only happens on my installation - yes, I'll be happy to create a ticket.
But I test many sites with different servers and at a different distance from me as a client to a server.
This waiting time on all the sites I've tested is throbbing in the same vague way.
That's why this topic is ... Look and if you can find a reason ...

Before creating this topic, I have done thousands of tests, incl. and a few tickets to my host. I wrote in the beginning about what the host replied.
Also, I have checked and tested sites with another software platform - I was looking for a similar amount of CSS and JS and content ... And yes, the overall status of these sites, according to test server readings is average - but the weird thing is that waiting time to test such sites varies from 100 - 190 ms, and very rarely up to 300 ms ...
But your platform with so many benefits failed in the first byte about a year ago, and it continues.
I'm sorry if this offends you, but these are my observations - and they are not a small amount ...

[yacenty]

We also have huge problem with TTFB, on 4.4.9 with many cache machanism we have about 300 to 800ms to serve page for guest.

for example:

On previous versions of IPB it was reduced to about 80-100ms

[rfcontreras]

My numbers

Nginx + php-fpm
Nginx Pagespseed
Memcache for invision forum
Opcache

 

PageSpeed Insights (Mobile)

 

PageSpeed insights Mobile (asking to remove unused CSS)

 

 

PageSpeed insights (desktop, with several widgets)

 

Zend Opcache (php 7.2)

 

Opcache hit rate

 

I've deployed another invision community running the same version on CloudFare, but the TTFB didn't moved.

 

Regards

[Adlago]

32 minutes ago, rfcontreras said:

but the TTFB didn't moved.

Do you have these results in several consecutive tests - example 5 tests through 1 min. Thanks

[Adlago]

In my test, your site has the same issue with waiting time. This is after my 3th test

Edited January 10, 2020 by Adlago

[rfcontreras]

43 minutes ago, Adlago said:

Do you have these results in several consecutive tests - example 5 tests through 1 min. Thanks

I've created an html file (https://www.espacioprofundo.com.ar/hola.html) which just displays "Hola" on the screen and the TTFB on several runs is on the 180 ms mark consistently.   Checking the same with the site homepage I get values from 240 to 600 ms. 

I know that DigitalOcean (my hosting company) do not have the best TTFB in the market. I've considered to use cloudfare but all nginx_pagepseed optimizations get lost.

Best Regards

[ASTRAPI]

Hello 🙂

Quote

we have about 300 to 800ms to serve page for guest

TFB and serve a page to guest are two different metrics. A TTFB of 300ms it is in acceptable terms. Maybe not the best but acceptable.

Quote

I've created an html file (https://www.espacioprofundo.com.ar/hola.html) which just displays "Hola" on the screen and the TTFB on several runs is on the 180 ms mark consistently.   Checking the same with the site homepage I get values from 240 to 600 ms. 

That's normal as testing a static page .html is a lot faster than the dynamic homepage. For the dynamic page you must hit your cache method and Mysql before you get the TTFB.

Quote

I know that DigitalOcean (my hosting company) do not have the best TTFB in the market.

There is no such thing, hosting with good or bad TTFB as there are many factors for TTFB. (Check below the different factors).

Quote

I've considered to use cloudfare but all nginx_pagepseed optimizations get lost.

Cloudflare offer all or at least almost all the optimizations of pagespeed and a few more i can say for images and also they have to use resources for that and not use your server resources like cpu,ram etc

I did some tests today and i was not able to hit that issue that Adlago report but maybe that's me and the issue exist or another issue exist that is adding that delay...

I think it will be good also to re post here some info about TTFB as it seems that there are many different understandings for the same thing:

 

Quote

In this case, I refer to the waiting time as part of the first byte.

The waiting time is related to:

TTFB factors

• Geographically relative source and target distance = how close test/visitor is to your server
• DNS, server connection & response time
• MySQL or database backend performance/settings
• Server hardware

Quote

My host plan is expensive and I expect the host company to fulfill contract parameters

Expensive is not something that will guaranty low TTFB. If they promise you that you will get a low TTFB because you will get a good server, that will never happen as i explain above the factors.

Examples of why it can't be done:

For example if you are hosting your nameservers/DNS: You can't compare that by using a reputable DNS provider like:

If for example your server is at Europe let's say Italy and your visitors in the US you can't get a TTFB at 200ms by hosting yourself your DNS.

Optimization of your Mysql is very important if you are testing a dynamic web site.

Another factor is your ssl certificate. Most users use Let's Encrypt RSA 2048bit  (that is great) but they have for all visitors the same certificate.

But not all visitors use some outdated Android devices and most of them can support more modern and faster certificates like an ECDSA 256bit.

So what i do is having both and let Nginx check which one to serve on each user. Using a new version of openssl also helps. Compiling by using a newer than the default GCC will help also.

There are a ton of little things that can save a few ms left and right but again for me the most important is to have the page rendering finish as soon as possible.

Of course having an expensive server it helps as you will probably get a cpu with some extra instructions set specific for ssl.

There is a lot more than getting an expensive server or get hosting A than hosting B.

So asking from Invision support to improve TTFB alone it will not help as your server should be optimized also very well and for sure you should consider the above TTFB factors. Unless that is a bug in the platform that adds that delay...

That's what i get from a client of me:

It never goes more than 150ms.

Thank you 🙂

 

 

Edited January 10, 2020 by ASTRAPI

[rfcontreras]

I've made several changes, disabled PageSpeed Nginx, deployed Clouflare (paid version), opcache, mariadb optimized, etc but my TTFB is awful, always on the 600-800 ms mark. 

If I create a CloudFlare page rule to cache everything (this is the case of Pages articles) TTFB is awesome (around 30 ms), but this cant be used on the forums since it would cache everything, unread post remains unread until CF Expires, etc.

What can be done to improve TTFB for the FORUMS ? I see the same average ttfb on the invision forum itself, on the 600-800 mark, not good imho.

Regards