linksderisar's avatar

Slow response times in Laravel (ca. 1 out of 10 requests)

Situation: 1 out of 10 requests to my application has a response time over > 500ms. All other requests are < 100ms. The route that i use for testing just outputs a simple hello as response. This is on my local homestead environment as well as on my linode (which is managed by laravel forge, btw). No database calls etc.

The strange thing is that as soon as i send more than 1 request at my app sequentially, response times get much better. Seems like some caching kicks in. The first request is always slow, the next ~9-12 are fine, then there's one slow again, the next ~9-12 are fine, and so on...

I can replicate this behavior with a small bash script, which sends requests after a 0.1s timeout. Using a 0.5s timeout yield worse response times, using a 0.05s timeout yields better response times.

Here is the script: $ for i in {1..100};do curl -s -w "%{time_total}\n" -o /dev/null http://app.dev/test; sleep 0.1; done

And the typical output:

0.778 <--- slow
0.047
0.061
0.043
0.072
0.071
0.052
0.057
0.052
0.075
0.060
0.851 <--- slow
0.066
0.055
0.072
0.067
0.044
0.057
0.057
0.081
0.058
0.040
0.067
0.047
0.804 <--- slow
0.066
0.050
0.055
0.041
0.064
0.061
0.046
0.059
0.055
0.057
0.071
0.045
...

I've tried tweaking nginx/php-fpm already (buffers etc), but to no avail.

I tried using blackfire.io to get some insights. Same situation: If i tell blackfire to only test "one time" (= "disable aggregation"), I get response times of 1.0s+, when enabling aggregation i get 0.2s on average (i think they do 10 requests). Here are the results for the curious:

1-time-run: https://blackfire.io/profiles/11dd92d7-2ddb-403e-918c-b884b7447b53/graph

10-time-run: https://blackfire.io/profiles/51bab4ca-a505-440e-b4e0-ea76a6bac5d3/graph

I am pretty sure it is a Laravel thing, because: The graphs for the two tests above (one time vs. 10 times) look absolutely different. I do not understand them fully yet (have to study a bit how to read them), but it seems that my "one time run" is spending much more time in the autoloader.

Doing php artisan optimize does not help (yes, I disabled debug in my env).

Hope this helps someone in this great community giving me a hint where to look next.

My question is: Does anybody know if the autoloader is doing some weird filesystem caching stuff that works for a few requests and then gets cleared, resulting in slower response times?

0 likes
3 replies

Please or to participate in this conversation.