1

While testing the local site I've noticed ~10x difference in time reported by Blackfire as compared to other sources.

The setup:

  • macOS High Sierra with all stack installed locally via Homebrew (similar to Laravel's Valet)
  • Nginx 1.13.9
  • PHP 7.2.3, with opcache
  • Xdebug 2.6.0 (disabled during profiling)
  • Blackfire agent 1.16.0
  • Blackfire probe 1.18.2
  • Latest WordPress with default theme and settings, created using custom Composer-powered skeleton where WP is a dependency itself
  • Composer's autoloader is optimized
  • HTTPS (self-signed, signed with custom local CA)
  • HTTP/2

The results:

  • Blackfire: 321ms
  • Chrome's Network timing (TTFB): 34.80ms
  • WordPress - Query Monitor plugin: 0.03s (or 30ms)
  • WordPress - Laps plugin: 0.029s (or 29ms)
  • CLI curl -s -o /dev/null \-w "%{time_total}\n" -k https://wp.test looped 10 times: AVG 0.044s (or 44ms, individual runs delta is 2-3ms)

Tested multiple times. All sources except Blackfire are pretty consistent and report time in 30-50ms range. Perceived load time is "instant" like a real 30-50ms is. 350ms load time would be noticeable, that's why I do believe the Blackfire is lying here.

What am I doing wrong? Haven't noticed this before.

Update:

  1. Tested some other php stuff - a basic file with phpinfo only, memcached and opcache admin scripts - all of them are super fast and Blackfire reports the same timing as other methods.
  2. Tested on Vagrant VM (Laravel's Homestead), all WordPress sites are fast, Blackfire also reports the same timing as other methods.

Considering the above, there's definitely something wrong with Blackfire + WordPress + macOS High Sierra with local EMP stack.

Ihor Vorotnov
  • 1,678
  • 1
  • 13
  • 22
  • So one is reporting from remote (blackfire) and the other is localhost (chrome)? – Lawrence Cherone Mar 22 '18 at 12:39
  • No, Blackfire is local. The probe is a local PHP extension, the agent is a local agent. Everything is on the same machine. Blackfire.io _remote_ website is used only for analyzing collected profile data. – Ihor Vorotnov Mar 22 '18 at 12:41

1 Answers1

1

Profiling code - in any language - adds some overhead. This depends on the engine, the code and some other variables like the computer running the profiled code. In your case, the overhead makes the page running 10x slower. The added slowness is isometric, it means you can reason and improve your code using the results.

Here's a pointer to Blackfire's documentation related to the overhead https://blackfire.io/docs/reference-guide/analyzing-call-graphs#understanding-blackfire-overhead

There's also a blog post from tideways about PHP 7, profiling and overhead https://tideways.io/profiler/blog/profiling-overhead-and-php-7

Romain Neutron
  • 81
  • 3
  • Hello Ihor. Your sarcastic comments regarding my answer makes me uncomfortable. I took some time to answer you. And I told you "some other variables like the computer running the profiled code". What you observe here, is that depending the environment, the profiling overhead vary. Cheers, – Romain Neutron Apr 10 '18 at 14:48
  • I re-read my comments and admit I was unnecessarily over sarcastic. Sorry for that. Deleted them, let's start fresh. I already excluded the impact of the overhead before asking the question. It's something else. Until now, I narrowed it down to filesystem related functions (require(_once), file_exists). So, it very well may be the APFS. – Ihor Vorotnov Apr 10 '18 at 16:49