, 5 min read
Simplified Saaze Monitored with PHPSPY
Original post is here eklausmeier.goip.de/blog/2023/10-29-simplified-saaze-monitored-with-phpspy.
This blog uses the PHP-based Simplified Saaze software. I measured Simplified Saaze using XHProf:
Still I am interested whether I missed anything.
In multiple talks Rasmus Lerdorf, the creator of PHP, advertises PHPSPY.
PHPSPY was written by Adam Saponara. The source code is in GitHub: https://github.com/adsr/phpspy.
I ran PHPSPY in top mode for some days using the dynamic mode of Simplified Saaze: phpspy -p 940 -p 17132 -p 61898 -p 61899 -t. The output is below. Some remarks on inclusive and exclusive times or counts:
- Inclusive counts everything for the function and all its function it calls.
- Exclusive only counts a particular function.
phpspy -p 940 -p 17132 -p 61898 -p 61899 -@
samp_count=666 err_count=10 func_count=67
tincl texcl incl excl excl% func
313 151 0 0 0.00 ComposerAutoloaderInit50920a90746408ba7a500bacdb4908c1::getLoader /home/klm/php/sndsaaze/vendor/composer/autoload_real.php:19
132 103 0 0 0.00 composerRequire50920a90746408ba7a500bacdb4908c1 /home/klm/php/sndsaaze/vendor/composer/autoload_real.php:50
99 99 0 0 0.00 Composer\Autoload\includeFile /home/klm/php/sndsaaze/vendor/composer/ClassLoader.php:569
76 76 0 0 0.00 json_decode <internal>:-1
298 34 0 0 0.00 Saaze\Saaze::run /home/klm/php/sndsaaze/vendor/eklausme/saaze/Saaze.php:32
30 30 0 0 0.00 ComposerAutoloaderInit50920a90746408ba7a500bacdb4908c1::loadClassLoader /home/klm/php/sndsaaze/vendor/composer/autoload_real.php:9
23 23 0 0 0.00 FFI::cdef <internal>:-1
19 19 0 0 0.00 file_get_contents <internal>:-1
15 15 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-mbstring/bootstrap.php:1
13 13 0 0 0.00 md4c_toHtml <internal>:-1
14 11 0 0 0.00 str_word_count <internal>:-1
10 10 0 0 0.00 yaml_parse <internal>:-1
322 9 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/autoload.php:1
90 9 0 0 0.00 Saaze\TemplateManager::<main> /home/klm/php/sndsaaze/templates/blog/entry.php:1
8 8 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-intl-grapheme/bootstrap.php:1
5 5 0 0 0.00 FFI::string <internal>:-1
653 4 0 0 0.00 <main> /home/klm/php/sndsaaze/public/index.php:1
5 4 0 0 0.00 Saaze\TemplateManager::<main> /home/klm/php/sndsaaze/templates/error.php:1
5 3 0 0 0.00 microtime <internal>:-1
4 3 0 0 0.00 strpos <internal>:-1
3 3 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-ctype/bootstrap.php:1
3 3 0 0 0.00 shell_exec <internal>:-1
27 2 0 0 0.00 Saaze\CollectionArray::loadCollections /home/klm/php/sndsaaze/vendor/eklausme/saaze/CollectionArray.php:27
21 2 0 0 0.00 <main> <internal>:-1
10 2 0 0 0.00 is_dir <internal>:-1
9 2 0 0 0.00 Saaze\Collection::__construct /home/klm/php/sndsaaze/vendor/eklausme/saaze/Collection.php:15
9 2 0 0 0.00 Saaze\TemplateManager::renderError /home/klm/php/sndsaaze/vendor/eklausme/saaze/TemplateManager.php:62
4 2 0 0 0.00 scandir <internal>:-1
3 2 0 0 0.00 strlen <internal>:-1
2 2 0 0 0.00 Saaze\TemplateManager::<main> /home/klm/php/sndsaaze/templates/top-layout.php:1
2 2 0 0 0.00 Saaze\MarkdownContentParser::inlineMath /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:172
2 2 0 0 0.00 strip_tags <internal>:-1
23 1 0 0 0.00 Saaze\MarkdownContentParser::toHtml /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:562
9 1 0 0 0.00 substr <internal>:-1
1 1 0 0 0.00 substr_replace <internal>:-1
1 1 0 0 0.00 usort <internal>:-1
1 1 0 0 0.00 printf <internal>:-1
1 1 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-intl-normalizer/bootstrap.php:1
1 1 0 0 0.00 ob_end_clean <internal>:-1
1 1 0 0 0.00 str_replace <internal>:-1
1 1 0 0 0.00 file_put_contents <internal>:-1
1 1 0 0 0.00 max <internal>:-1
1 1 0 0 0.00 is_readable <internal>:-1
111 0 0 0 0.00 Saaze\Collection::loadMkdwnRecursive /home/klm/php/sndsaaze/vendor/eklausme/saaze/Collection.php:70
91 0 0 0 0.00 Saaze\TemplateManager::renderEntry /home/klm/php/sndsaaze/vendor/eklausme/saaze/TemplateManager.php:37
Interestingly, the time spent by Composer-classes is greater than the actual runtime of Simplified Saaze!
Added 11-Dec-2023: Measured once again. Results are below.
phpspy -p 879 -p 1015 -p 1016 -p 20333 -@
samp_count=2422 err_count=55 func_count=97
tincl texcl incl excl excl% func
1077 491 0 0 0.00 ComposerAutoloaderInit50920a90746408ba7a500bacdb4908c1::getLoader /home/klm/php/sndsaaze/vendor/composer/autoload_real.php:19
506 369 0 0 0.00 composerRequire50920a90746408ba7a500bacdb4908c1 /home/klm/php/sndsaaze/vendor/composer/autoload_real.php:50
353 353 0 0 0.00 json_decode <internal>:-1
335 335 0 0 0.00 Composer\Autoload\includeFile /home/klm/php/sndsaaze/vendor/composer/ClassLoader.php:569
81 81 0 0 0.00 md4c_toHtml <internal>:-1
76 76 0 0 0.00 ComposerAutoloaderInit50920a90746408ba7a500bacdb4908c1::loadClassLoader /home/klm/php/sndsaaze/vendor/composer/autoload_real.php:9
75 75 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-mbstring/bootstrap.php:1
459 69 0 0 0.00 Saaze\TemplateManager::<main> /home/klm/php/sndsaaze/templates/blog/entry.php:1
67 67 0 0 0.00 FFI::cdef <internal>:-1
58 58 0 0 0.00 file_get_contents <internal>:-1
48 35 0 0 0.00 str_word_count <internal>:-1
1162 29 0 0 0.00 Saaze\Saaze::run /home/klm/php/sndsaaze/vendor/eklausme/saaze/Saaze.php:32
28 28 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-intl-grapheme/bootstrap.php:1
26 26 0 0 0.00 yaml_parse <internal>:-1
1096 23 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/autoload.php:1
22 20 0 0 0.00 scandir <internal>:-1
21 20 0 0 0.00 strpos <internal>:-1
491 19 0 0 0.00 Saaze\TemplateManager::renderEntry /home/klm/php/sndsaaze/vendor/eklausme/saaze/TemplateManager.php:37
21 16 0 0 0.00 microtime <internal>:-1
16 16 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-ctype/bootstrap.php:1
32 15 0 0 0.00 substr <internal>:-1
74 14 0 0 0.00 <main> <internal>:-1
2384 12 0 0 0.00 <main> /home/klm/php/sndsaaze/public/index.php:1
15 12 0 0 0.00 Saaze\MarkdownContentParser::inlineMath /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:172
12 12 0 0 0.00 strip_tags <internal>:-1
20 11 0 0 0.00 is_dir <internal>:-1
12 10 0 0 0.00 Saaze\TemplateManager::<main> /home/klm/php/sndsaaze/templates/top-layout.php:1
7 7 0 0 0.00 str_replace <internal>:-1
260 6 0 0 0.00 Saaze\Collection::loadEntry /home/klm/php/sndsaaze/vendor/eklausme/saaze/Collection.php:82
159 6 0 0 0.00 Saaze\MarkdownContentParser::toHtml /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:562
8 6 0 0 0.00 FFI::string <internal>:-1
6 6 0 0 0.00 shell_exec <internal>:-1
233 5 0 0 0.00 Saaze\Entry::getContentAndExcerpt /home/klm/php/sndsaaze/vendor/eklausme/saaze/Entry.php:86
6 5 0 0 0.00 <main> /home/klm/php/sndsaaze/vendor/symfony/polyfill-intl-normalizer/bootstrap.php:1
5 5 0 0 0.00 function_exists <internal>:-1
71 4 0 0 0.00 Saaze\CollectionArray::loadCollections /home/klm/php/sndsaaze/vendor/eklausme/saaze/CollectionArray.php:27
50 4 0 0 0.00 Saaze\Entry::parseEntry /home/klm/php/sndsaaze/vendor/eklausme/saaze/Entry.php:21
6 4 0 0 0.00 Saaze\TemplateManager::<main> /home/klm/php/sndsaaze/templates/error.php:1
6 4 0 0 0.00 is_readable <internal>:-1
21 3 0 0 0.00 Saaze\Collection::__construct /home/klm/php/sndsaaze/vendor/eklausme/saaze/Collection.php:15
5 3 0 0 0.00 Saaze\TemplateManager::<main> <internal>:-1
4 3 0 0 0.00 Saaze\MarkdownContentParser::myTag /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:212
3 3 0 0 0.00 substr_replace <internal>:-1
3 3 0 0 0.00 max <internal>:-1
3 3 0 0 0.00 Saaze\MarkdownContentParser::displayMath /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:145
3 3 0 0 0.00 dirname <internal>:-1
3 3 0 0 0.00 getenv <internal>:-1
3 3 0 0 0.00 rtrim <internal>:-1
549 2 0 0 0.00 Saaze\Collection::loadMkdwnRecursive /home/klm/php/sndsaaze/vendor/eklausme/saaze/Collection.php:70
72 2 0 0 0.00 Saaze\Config::init /home/klm/php/sndsaaze/vendor/eklausme/saaze/Config.php:14
20 2 0 0 0.00 Saaze\Collection::parseCollection /home/klm/php/sndsaaze/vendor/eklausme/saaze/Collection.php:22
16 2 0 0 0.00 Saaze\MarkdownContentParser::gallery /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:397
5 2 0 0 0.00 date <internal>:-1
3 2 0 0 0.00 strlen <internal>:-1
2 2 0 0 0.00 ltrim <internal>:-1
2 2 0 0 0.00 Saaze\Collection::Saaze\{closure} /home/klm/php/sndsaaze/vendor/eklausme/saaze/Collection.php:54
2 2 0 0 0.00 Saaze\TemplateManager::templateExists /home/klm/php/sndsaaze/vendor/eklausme/saaze/TemplateManager.php:7
2 2 0 0 0.00 Saaze\MarkdownContentParser::twitter /home/klm/php/sndsaaze/vendor/eklausme/saaze/MarkdownContentParser.php:333
2 2 0 0 0.00 fopen <internal>:-1
2 2 0 0 0.00 Composer\Autoload\ClassLoader::register /home/klm/php/sndsaaze/vendor/composer/ClassLoader.php:389
2 2 0 0 0.00 strtotime <internal>:-1
192 1 0 0 0.00 Saaze\Entry::__construct /home/klm/php/sndsaaze/vendor/eklausme/saaze/Entry.php:13
10 1 0 0 0.00 Saaze\Entry::getUrl /home/klm/php/sndsaaze/vendor/eklausme/saaze/Entry.php:74
4 1 0 0 0.00 ob_end_clean <internal>:-1
Results are similar. Clearly even more accentuating the importance of Composer.