diff --git a/Makefile.frag b/Makefile.frag new file mode 100644 index 0000000..a042552 --- /dev/null +++ b/Makefile.frag @@ -0,0 +1,11 @@ + +spx_ui_assets_dir = $(prefix)/share/misc/php-spx/assets/web-ui + +CFLAGS += -DSPX_HTTP_UI_ASSETS_DIR=\"$(spx_ui_assets_dir)\" + +install-spx-ui-assets: + @echo "Installing SPX web UI to: $(spx_ui_assets_dir)" + @mkdir -p $(spx_ui_assets_dir) + @cp -r assets/web-ui/* $(spx_ui_assets_dir) + +install: $(all_targets) $(install_targets) install-spx-ui-assets diff --git a/README.md b/README.md index cc442fd..c8872cb 100644 --- a/README.md +++ b/README.md @@ -2,32 +2,36 @@ [![Build Status](https://travis-ci.org/NoiseByNorthwest/php-spx.svg?branch=master)](https://travis-ci.org/NoiseByNorthwest/php-spx) ![Supported PHP versions: 5.6 .. 7.x](https://img.shields.io/badge/php-5.6,%207.x-blue.svg) -![Showcase](docs/fp1.gif) +![Showcase](assets/docs/fp1.gif) + +![Showcase](assets/docs/as.png) SPX, which stands for _Simple Profiling eXtension_, is just another profiling extension for PHP. It differentiates itself from other similar extensions as being: * totally free and confined to your infrastructure (i.e. no data leaks to a SaaS). -* very simple to use: just set an environment variable (command line script) or a query string parameter (web page) to get a flat profile as output. Thus, you are free of: - * manually instrumenting your code (Ctrl-C a long running script is even supported as icing on the cake). - * using a dedicated browser extension. - * using a dedicated analysis tool. +* very simple to use: just set an environment variable (command line) or switch on a radio button (web page) to profile your script. Thus, you are free of: + * manually instrumenting your code (Ctrl-C a long running command line script is even supported). + * using a dedicated browser extension or command line launcher. * [multi metrics](#available-metrics) capable: 10 currently supported (various time metrics, memory, objects in use, I/O...). -* [multi output formats](#available-outputs) capable: SPX does not require external / third party analysis tool as it can produce flat profile, which is sufficient in most cases, on its own. However, when you need to perform deeper analysis, SPX can output profile data in the following **interoperable** formats: - * Google's [Trace Event Format](https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview) to be analyzed with Chromium's / Chrome's [about:tracing](https://www.chromium.org/developers/how-tos/trace-event-profiling-tool). - * [Callgrind format](http://valgrind.org/docs/manual/cl-format.html) to be analyzed with [KCachegrind](https://kcachegrind.github.io/html/Home.html) or similar. +* shipped with its [web UI](#web-ui) which allows to: + * enable / configure profiling for the current browser session + * list profiled script reports + * select a report for in-depth analysis, featuring these interactive visualizations: + * time line + * flat profile + * flame graph ## Requirements -This extension was primarily developed for my own usage and currently only fit my personal requirements: +Platforms support is currently quite limited. Feel free to open an issue if your platform is not supported. +Current requirements are: * x86-64 -* GNU/Linux or macOS +* **GNU/Linux** or **macOS** * zlib dev package (e.g. zlib1g-dev on Debian based distro) * PHP 5.6 & 7+ * Non-ZTS (threaded) build of PHP (ZTS support is theoretical) -Feel free to open an issue if your platform is not supported. - ## Installation ### Prerequisites @@ -48,7 +52,7 @@ sudo make install ``` Then add `extension=spx.so` to your *php.ini*, or in a dedicated *spx.ini* file created within the include directory. -You may also want to override [default SPX configuration](#configuration) to be able to profile HTTP requests. +You may also want to override [default SPX configuration](#configuration) to be able to profile a web page, with [this one](#private-environment) for example for a local development environment. ## Development status @@ -58,12 +62,11 @@ You can still safely use it in a **non-production** environment. Contributions are welcome but be aware of the experimental status of this project and **please follow the contribution rules** described here: [CONTRIBUTING.md](CONTRIBUTING.md) - ## Basic usage -### CLI script +### Command line script -Just prepend your command line with `SPX_ENABLED=1` to trigger profiling. You will get flat profile printed on STDOUT at the end of the execution, even if you abort it by hitting Ctrl-C, as in the following example: +Just prepend your command line with `SPX_ENABLED=1` to trigger profiling. You will get the flat profile printed on STDOUT at the end of the execution, even if you abort it by hitting Ctrl-C, as in the following example: ```shell $ SPX_ENABLED=1 composer update @@ -74,255 +77,284 @@ Updating dependencies (including require-dev) Global stats: - Called functions : 19.2M - Distinct functions : 726 + Called functions : 27.5K + Distinct functions : 714 - Wall Time : 24.14s - ZE memory : 506.3MB + Wall Time : 7.39s + ZE memory : 62.6MB Flat profile: Wall Time | ZE memory | Inc. | *Exc. | Inc. | Exc. | Called | Function ----------+----------+----------+----------+----------+---------- - 9.07s | 9.05s | 59.3MB | 59.0MB | 80 | Composer\Util\RemoteFilesystem::get - 3.23s | 3.23s | 9.8KB | 9.8KB | 108 | Composer\Cache::sha256 - 10.48s | 1.62s | 256.3MB | -52.2MB | 328 | Composer\DependencyResolver\RuleSetGenerator::addRulesForPackage - 2.42s | 1.15s | 100.0MB | 100.0MB | 1.2M | Composer\DependencyResolver\RuleSet::add - 760.6ms | 760.6ms | 0B | 0B | 1.2M | Composer\DependencyResolver\Rule2Literals::getHash - 726.5ms | 513.5ms | 0B | 0B | 1.2M | Composer\DependencyResolver\Rule2Literals::__construct - 544.0ms | 423.4ms | 37.1MB | 37.1MB | 470.1K | Composer\DependencyResolver\RuleWatchGraph::insert - 309.0ms | 232.2ms | 0B | -165.9MB | 470.1K | Composer\DependencyResolver\RuleWatchNode::__construct - 103.8ms | 103.8ms | 0B | 0B | 470.1K | Composer\DependencyResolver\RuleSetIterator::next - 69.3ms | 69.3ms | 0B | 0B | 470.1K | Composer\DependencyResolver\RuleSetIterator::current + 101.6ms | 101.6ms | 41.8MB | 41.8MB | 12 | Composer\Json\JsonFile::parseJson + 53.6ms | 53.6ms | 544B | 544B | 4 | Composer\Cache::sha256 + 6.91s | 41.5ms | 41.5MB | -7.5MB | 4 | Composer\Repository\ComposerRepository::fetchFile + 6.85s | 32.3ms | 47.5MB | 5.4MB | 5 | 1@Composer\Repository\ComposerRepository::loadProviderListings + 7.8ms | 7.8ms | 0B | 0B | 4 | Composer\Cache::write + 1.1ms | 1.1ms | -72B | -72B | 1 | Composer\Console\Application::Composer\Console\{closure} + 828.5us | 828.5us | 976B | 976B | 12 | Composer\Util\RemoteFilesystem::findHeaderValue + 497.6us | 491.0us | 710.2KB | 710.2KB | 1 | Composer\Cache::read + 2.4ms | 332.6us | 20.9KB | -378.8KB | 34 | 3@Symfony\Component\Finder\Iterator\FilterIterator::rewind + 298.9us | 298.9us | 2.2KB | 2.2KB | 47 | Symfony\Component\Finder\Iterator\FileTypeFilterIterator::accept ``` -### HTTP request +### Web page -Assuming a development environment with the configuration [described here](#private-environment). -You just have to append `SPX_KEY=dev&SPX_ENABLED=1` to the query string of your application URL to get flat profile in place of the original output, as in the following example: +Assuming a development environment with the configuration [described here](#private-environment) and your application is accessible via `http://localhost`. -```shell -$ curl 'localhost?SPX_KEY=dev&SPX_ENABLED=1' +Just open with your browser the following URL: `http://localhost/_spx?SPX_KEY=dev` to access to the web UI [control panel](#control-panel). You will see the following form: -*** SPX Report *** +![Showcase](assets/docs/cp-form.png) -Global stats: +Then switch on "Enabled". At this point profiling is enabled for the current domain and your current browser session through a set of dedicated cookies. - Called functions : 8.9K - Distinct functions : 1.1K +Then refresh the web page you want to profile and refresh the control panel to see the generated report in the list below the control panel form. - Wall Time : 73.2ms - ZE memory : 11.3MB +![Showcase](assets/docs/cp-list2.png) -Flat profile: +Then click on the report in the list and enjoy the [analyze screen](#analyze-screen). - Wall Time | ZE memory | - Inc. | *Exc. | Inc. | Exc. | Called | Function -----------+----------+----------+----------+----------+---------- - 48.8ms | 40.8ms | 9.2MB | 9.2MB | 472 | Symfony\Component\Debug\DebugClassLoader::loadClass - 5.9ms | 3.7ms | 819.5KB | 517.1KB | 67 | Symfony\Component\VarDumper\Cloner\VarCloner::doClone - 993us | 993us | 1.6KB | 1.6KB | 31 | Symfony\Bridge\Monolog\Handler\ServerLogHandler::createSocket - 1.1ms | 905us | 724.6KB | 601.2KB | 14 | Symfony\Component\HttpKernel\DataCollector\DataCollector::serialize - 712us | 712us | 287.2KB | 287.2KB | 1 | Symfony\Component\HttpKernel\DataCollector\LoggerDataCollector::getContainerCompilerLogs - 488us | 488us | 335.5KB | 335.5KB | 16 | Symfony\Component\VarDumper\Cloner\AbstractCloner::addCasters - 1.7ms | 423us | 99.1KB | -669.6KB | 1 | Symfony\Component\HttpKernel\Profiler\FileProfilerStorage::write - 2.2ms | 310us | 302.4KB | -63.3KB | 74 | Symfony\Component\VarDumper\Cloner\AbstractCloner::castObject - 299us | 299us | 144.1KB | 144.1KB | 74 | Symfony\Component\VarDumper\Caster\Caster::castObject - 220us | 220us | 123.4KB | 123.4KB | 74 | Symfony\Component\VarDumper\Cloner\Stub::serialize +## Advanced usage + +### Configuration + +| Name | Default | Changeable | Description | +| --------------------- | -------- | ----------- | ------------ | +| spx.data_dir | `/tmp/spx` | PHP_INI_SYSTEM | The directory where profiling reports will be stored. You may change it to point to a shared file system for example in case of multi-server architecture. | +| spx.http_enabled | `0` | PHP_INI_SYSTEM | Whether to enable web UI and HTTP request profiling. | +| spx.http_key | | PHP_INI_SYSTEM | The secret key used for authentication (see [security concern](#security-concern) for more details). You can use the following command to generate a 16 bytes random key as an hex string: `openssl rand -hex 16`. | +| spx.http_ip_var | `REMOTE_ADDR` | PHP_INI_SYSTEM | The `$_SERVER` key holding the client IP address used for authentication (see [security concern](#security-concern) for more details). Overriding the default value is required when your application is behind a reverse proxy. | +| spx.http_ip_whitelist | | PHP_INI_SYSTEM | The IP address white list used for authentication as a comma separated list of IP addresses. | +| spx.http_ui_assets_dir | `/usr/local/share/misc/php-spx/assets/web-ui` | PHP_INI_SYSTEM | The directory where the [web UI](#web-ui) files are installed. In most cases you do not have to change it. | +| spx.http_ui_uri_prefix | `/_spx` | PHP_INI_SYSTEM | The request-URI prefix to access to the [web UI](#web-ui). You may change it for various reasons (additional security factor, conflict with existing URI, ...). | +#### Private environment + +For your local & private development environment, since there is no need for authentication, you can use this configuration: + +``` +spx.http_enabled=1 +spx.http_key="dev" +spx.http_ip_whitelist="127.0.0.1" ``` -See more complex examples [here](#examples). +And then access to the web UI at `http(s):///_spx?SPX_KEY=dev`. -## Advanced usage +### Available metrics + +Here is the list of available metrics to collect. By default only _Wall Time_ and _Zend Engine memory_ are collected. + +| Key (command line) | Name | Description | +| ---- | ---------------- | ------ | +| _wt_ | Wall Time | The absolute elapsed time. | +| _ct_ | CPU Time | The time spent while running on CPU. | +| _it_ | Idle Time | The time spent off-CPU, that means waiting for CPU, I/O completion, a lock acquisition... or explicitly sleeping. | +| _zm_ | Zend Engine memory | Zend Engine memory usage. Equivalent to `memory_get_usage(false)`. | +| _zr_ | Zend Engine root buffer length | Root buffer length, see explanation [here](http://php.net/manual/en/features.gc.collecting-cycles.php). It could be helpful to track pressure on garbage collector. | +| _zo_ | Zend Engine object count | Number of objects currently held by user code. | +| _ze_ | Zend Engine error count | Number of raised PHP errors. | +| _io_ | I/O (reads + writes) | Bytes read or written while performing I/O. | +| _ior_ | I/O (reads) | Bytes read while performing I/O. | +| _iow_ | I/O (writes) | Bytes written while performing I/O. | + +_N.B.: I/O metrics are not supported on macOS._ + +### Command line script + +#### Available report types + +Contrary to web page profiling which only support _full_ report type (the one exploitable by the web UI), command line script profiling supports several types of report. +Here is the list below: -### Parameters +| Key | Name | Description | +| ---- | ----- | ------------ | +| _fp_ | Flat profile | The flat profile provided by SPX. It is the **default report type** and is directly printed on STDOUT. | +| _full_ | Full report | This is the report type for web UI. Reports will be stored in SPX data directory and thus will be available for analysis on web UI side. | +| _trace_ | Trace file | A custom format (human readable text) trace file. | #### Available parameters | Name | Default | Description | | ----- | -------- | ------------ | -| SPX_KEY | | The secret key, required for [HTTP request profiling](#security-concern). | -| SPX_ENABLED | 0 | Whether to enable SPX profiler (i.e. triggering profiling). When disabled there is no performance impact on your application. | -| SPX_BUILTINS | 0 | Whether to instrument internal functions. | -| SPX_DEPTH | 0 | The stack depth at which profiling must stop (i.e. aggregate measures of deeper calls). 0 (default value) means unlimited. | -| SPX_METRICS | wt,zm | Comma separated list of [available metric keys](#available-metrics) to monitor. All output types, except Google's Trace Event Format, take advantage of multi-metric profiling. | -| SPX_OUTPUT | fp | Selected [output key](#available-outputs). | -| SPX_OUTPUT_FILE | | CLI only. Custom output file. If not specified it will be generated in `/tmp` and displayed on STDERR at the end of the script. | -| SPX_FP_FOCUS | wt | [Metric key](#available-metrics) for flat profile sort. | -| SPX_FP_INC | 0 | Whether to sort functions by inclusive value instead of exclusive value in flat profile. | -| SPX_FP_REL | 0 | Whether to display metric values as relative (i.e. percentage) in flat profile. | -| SPX_FP_LIMIT | 10 | The flat profile size (i.e. top N shown functions). | -| SPX_FP_LIVE | 0 | For CLI only. Whether to enabled flat profile live refresh. Since it uses ANSI escape sequences, it uses STDOUT as output, replacing script output (both STDOUT & STDERR). It also does not work if you have specified a custom output file. | -| SPX_TRACE_SAFE | 0 | The trace file is by default written in a way to enforce accuracy, but in case of process crash (e.g. segfault) some logs could be lost. If you want to enforce security (e.g. to find the last event before a crash) you just have to set this parameter to 1. | +| _SPX_ENABLED_ | `0` | Whether to enable SPX profiler (i.e. triggering profiling). When disabled there is no performance impact on your application. | +| _SPX_BUILTINS_ | `0` | Whether to profile internal functions. | +| _SPX_DEPTH_ | `0` | The stack depth at which profiling must stop (i.e. aggregate measures of deeper calls). 0 (default value) means unlimited. | +| _SPX_METRICS_ | `wt,zm` | Comma separated list of [available metric keys](#available-metrics) to collect. All report types take advantage of multi-metric profiling. | +| _SPX_REPORT_ | `fp` | Selected [report key](#available-report-types). | +| _SPX_FP_FOCUS_ | `wt` | [Metric key](#available-metrics) for flat profile sort. | +| _SPX_FP_INC_ | `0` | Whether to sort functions by inclusive value instead of exclusive value in flat profile. | +| _SPX_FP_REL_ | `0` | Whether to display metric values as relative (i.e. percentage) in flat profile. | +| _SPX_FP_LIMIT_ | `10` | The flat profile size (i.e. top N shown functions). | +| _SPX_FP_LIVE_ | `0` | Whether to enabled flat profile live refresh. Since it uses ANSI escape sequences, it uses STDOUT as output, replacing script output (both STDOUT & STDERR). | +| _SPX_FULL_RES_ | `0` | The time resolution for full report in micro seconds (0 means unlimited). When profiling a long running & CPU intensive script, this option will allow you to contain report size and thus keeping it small enough to be exploitable by the [web UI](#web-ui). See [here](#performance-report-size--time-resolution) for more details. | +| _SPX_TRACE_SAFE_ | `0` | The trace file is by default written in a way to enforce accuracy, but in case of process crash (e.g. segfault) some logs could be lost. If you want to enforce durability (e.g. to find the last event before a crash) you just have to set this parameter to 1. | +| _SPX_TRACE_FILE_ | | Custom trace file name. If not specified it will be generated in `/tmp` and displayed on STDERR at the end of the script. | -#### Setting parameters for CLI script +#### Setting parameters -Well, as you might already noticed in corresponding [basic usage example](#cli-script), setting a SPX parameter for a CLI script simply means setting an environment variable with the same name. +Well, as you might already noticed in corresponding [basic usage example](#command-line-script), setting a SPX parameter for a command line script simply means setting an environment variable with the same name. -#### Setting parameters for HTTP request +### Web UI -When profiling an HTTP request, there are 2 ways to set SPX parameters: - - as a query string parameter: `https://...?SPX_KEY=`. - - as a request header: `SPX-KEY: `. Since underscores (`_`) are not allowed in header field name, you have to replace them with an en dash (`-`). +#### Supported browsers -_N.B.: Query string parameters have higher precedence than request headers._ +Since the web UI uses advanced JavaScript features, only the following browsers are supported: +- most recent version of any Chromium-based browser. +- most recent version of Firefox with `dom.moduleScripts.enabled` preference set to `true`. -### HTTP +_You will have the best user experience with a Chromium-based browser._ -#### Security concern +#### Control panel & report list -_The lack of review / feedback about this concern is the main reason **SPX cannot yet be considered as production ready**._ +This is the home page of the web UI, divided into 2 parts: +- the control panel for setting the profiling setup for your current browser session. +- the profile report list as a sortable table. A click on a row allows to go to the [analyze screen](#analyze-screen) for the corresponding report. -SPX allows you to profile HTTP request as well as CLI scripts. In this case, and for ease of use, SPX replaces normal output by its own (as text/plain response or custom format as attachment). -This is why there is a huge security risk, since an attacker could: - - steal SPX output and get sensible information about your application. - - to a lesser extent, make a DoS attack against your application with a costly SPX profiling setup. +#### Analyze screen -So, unless access to your application is already restricted at lower layer (i.e. before your application is hit, not by the application / PHP framework itself), a client triggering SPX profiling must be authenticated. +##### Performance, report size & time resolution -SPX enforces authentication with 2 mandatory locks: -* IP address white list (exact string representation matching). -* Fixed secret random key (generated on your own) provided via a [request header or query string parameter](#http-1). +The analyze screen can nicely handle profile reports with up to several (5+) millions of recorded function calls with Chromium on my i5 @ 3.3GHz / 8GB desktop. +In case you want to profile a long running, CPU intensive, script which tends to generate giant reports, you can change the time resolution of the report to skip the shortest function calls (i.e. those with execution time below the given resolution). +See _SPX_FULL_RES_ [parameter](#available-parameters) for command line script. -Thus a client can profile your application via an HTTP request only if **its IP address is white listed and its provided key is valid**. +##### Metric selector -#### Configuration +This is simply a combo box for selecting the currently analyzed metric. -| Name | Default | Changeable | Description | -| --------------------- | -------- | ----------- | ------------ | -| spx.http_enabled | 0 | PHP_INI_SYSTEM | Whether to enable profiling of HTTP requests. | -| spx.http_key | | PHP_INI_SYSTEM | The secret key. You can use the following command to generate a 16 bytes random key as an hex string: `openssl rand -hex 16`. | -| spx.http_ip_var | REMOTE_ADDR | PHP_INI_SYSTEM | The `$_SERVER` key holding the client IP address. Overriding the default value is required when your application is behind a reverse proxy. | -| spx.http_ip_whitelist | | PHP_INI_SYSTEM | The IP address white list as a comma separated list of IP addresses. | +![Showcase](assets/docs/as-ms.png) -##### Private environment +##### Time line overview -For your local & private development environment, since there is no need for authentication, you can use this configuration: +This visualization is the time line overview of all called functions. +You can change the selected time range by, represented by a transparent green rectangle, by simply dragging it horizontally. -``` -spx.http_enabled=1 -spx.http_key="dev" -spx.http_ip_whitelist="127.0.0.1" -``` +Except for wall time, the current metric is also plotted (current value over time) on a foreground layer. -And then trigger profiling by appending `?SPX_KEY=dev&SPX_ENABLED=1` to your application URL. +![Showcase](assets/docs/as-ov.png) -#### Best practices +##### Time line focus - - You should prefer profiling secured (HTTPS) URLs only. - - You should prefer set `SPX_KEY` via an HTTP header instead of a query string parameter. - - You can take advantage of an header management browser extension for ease of use, but **do not forget to restrict SPX headers to your domain**. +This visualization is an interactive time line which is able to control and keep focus on the selected time range. -### Metrics +Supported controls: +- left click drag: time range shift (horizontal) or depth range shift (vertical) +- middle click vertical drag: time range zoom in/out +- mouse wheel: time range zoom in/out +- hovering a function call to show more details -#### Available metrics +Except for wall time, the current metric is also plotted (current value over time) on a foreground layer. -| Key | Name | Description | -| ---- | ---------------- | ------ | -| _wt_ | Wall Time | The absolute elapsed time. | -| _ct_ | CPU Time | The time spent while running on CPU. | -| _it_ | Idle Time | The time spent off CPU, that means waiting for CPU, I/O completion, a lock acquisition... or explicitly sleeping. | -| _zm_ | Zend Engine memory | Zend Engine memory usage. Equivalent to `memory_get_usage(false)`. | -| _zr_ | Zend Engine root buffer length | Root buffer length, see explanation [here](http://php.net/manual/en/features.gc.collecting-cycles.php). It could be helpful to track pressure on garbage collector. | -| _zo_ | Zend Engine object count | Number of objects currently held by user code. | -| _ze_ | Zend Engine error count | Number of raised PHP errors. | -| _io_ | I/O (reads + writes) | Bytes read or written while performing I/O. | -| _ior_ | I/O (reads) | Bytes read while performing I/O. | -| _iow_ | I/O (writes) | Bytes written while performing I/O. | +![Showcase](assets/docs/as-tl.png) +##### Flat profile -_N.B.: I/O metrics are not supported on macOS._ +This visualization is the flat profile for the selected time range and the selected metric, displayed as a sortable table. -### Outputs +![Showcase](assets/docs/as-fp.png) -#### Available outputs +##### Flame Graph -| Key | Name | Supported metrics | Multi metrics | Description | -| ---- | ----- | ------------------ |--------------- | ------------ | -| _fp_ | Flat profile | All | Yes | The flat profile provided by SPX. It is the default output and is directly printed on STDOUT (CLI) or in place of response body (HTTP). | -| _cg_ | Callgrind | All | Yes | A file in [Callgrind format](http://valgrind.org/docs/manual/cl-format.html) to be analyzed with [KCachegrind](https://kcachegrind.github.io/html/Home.html) or similar. | -| _gte_ | Google's Trace Event Format | Time metrics | No | A file in Google's [Trace Event Format](https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview) to be analyzed with Chromium's / Chrome's [about:tracing](https://www.chromium.org/developers/how-tos/trace-event-profiling-tool). | -| _trace_ | Trace file | All | Yes | A custom format (human readable text) trace file. | +This visualization, designed by [Brendan Gregg](http://www.brendangregg.com/flamegraphs.html), allows to quickly find the hot code path for the selected time range and the selected metric. +Metrics corresponding to releasable resources (memory, objects in use...) are not supported by this visualization. -## Examples +![Showcase](assets/docs/as-fg.png) -### HTTP request / KCachegrind +## Security concern -Just run the following command: +_The lack of review / feedback about this concern is the main reason **SPX cannot yet be considered as production ready**._ -```shell -curl --compressed 'localhost?SPX_KEY=dev&SPX_ENABLED=1&SPX_METRICS=wt,zm,zo&SPX_OUTPUT=cg' > callgrind.out -``` +SPX allows you to profile web page as well as command line scripts, and also to list and analyze profile reports through its embedded web UI. +This is why there is a huge security risk, since an attacker could: + - access to web UI and get sensible information about your application. + - to a lesser extent, make a DoS attack against your application with a costly profiling setup. -And then open _callgrind.out_ with KCachegrind. You will be able to explore the call-graph in many ways, over the 3 specified metrics (wt, ze & zo). +So, unless access to your application is already restricted at lower layer (i.e. before your application is hit, not by the application / PHP framework itself), a client triggering profiling or accessing to the web UI must be authenticated. -![KCachegrind](docs/cg1.png) +SPX provides two-factor authentication with these 2 mandatory locks: +* IP address white list (exact string representation matching). +* Fixed secret random key (generated on your own) provided via a request header, cookie or query string parameter. +Thus a client can profile your application via a web page only if **its IP address is white listed and its provided key is valid**. -### HTTP request / about:tracing +## Notes on accuracy -Just run: +Being a tracing profiler, SPX is subject to accuracy issues for time related metrics when the measured function execution time is: +- close or lower than the timer precision +- close or lower than SPX's own per function overhead -```shell -curl --compressed 'localhost?SPX_KEY=dev&SPX_ENABLED=1&SPX_OUTPUT=gte' > trace.json -``` +The first issue is mitigated by using the highest resolution timer provided by the platform. For example the Linux timer resolution is 1ns while the macOS timer resolution is only 1us. -And then open _trace.json_ with Chromium's / Chrome's about:tracing application to get this timeline visualization: +The second issue is mitigated by taking in account SPX time (wall / cpu) overhead by subtracting it to measured function execution time. This is done by evaluating SPX constant per function overhead before starting profiling the script. -![about:tracing](docs/gte1.png) +However, whatever the platform, if you want to maximize accuracy to find a time bottleneck, you should also: +- avoid profiling internal functions. +- avoid collecting additional metrics. +- try to play with maximum depth parameter to stop profiling at a given depth. -### CLI script / trace file +## Examples + +### Command line script: generate report for web UI -The following command will trace all (user land) function calls of _./bin/console_ script in _trace.txt_ file. +To profile a command line script and generate a report available for the web UI you just have to select `full` report as in the following example: ```shell -$ SPX_ENABLED=1 SPX_OUTPUT=trace SPX_OUTPUT_FILE=trace.txt ./bin/console > /dev/null && head -20 trace.txt && echo ... && tail -20 trace.txt +SPX_ENABLED=1 SPX_REPORT=full ./bin/console cache:clear +``` + +### Command line script: generate trace file + +The following command will trace all (user) function calls of _./bin/console_ script in _trace.txt_ file. + +```shell +$ SPX_ENABLED=1 SPX_REPORT=trace SPX_TRACE_FILE=trace.txt ./bin/console > /dev/null && head -20 trace.txt && echo ... && tail -20 trace.txt + +SPX trace file: trace.txt Wall Time | ZE memory | Cum. | Inc. | Exc. | Cum. | Inc. | Exc. | Depth | Function ----------+----------+----------+----------+----------+----------+----------+---------- - 0us | 0us | 0us | 0B | 0B | 0B | 1 | +/home/sylvain/dev/sf_app/bin/console - 994us | 0us | 0us | 1.3KB | 0B | 0B | 2 | +/home/sylvain/dev/sf_app/vendor/autoload.php - 1.3ms | 0us | 0us | 11.3KB | 0B | 0B | 3 | +/home/sylvain/dev/sf_app/vendor/composer/autoload_real.php - 1.3ms | 3us | 3us | 11.3KB | 0B | 0B | 3 | -/home/sylvain/dev/sf_app/vendor/composer/autoload_real.php - 1.3ms | 0us | 0us | 10.9KB | 0B | 0B | 3 | +ComposerAutoloaderInita657e2f64bf98eb70db4e96bba0d4058::getLoader - 1.3ms | 0us | 0us | 11.9KB | 0B | 0B | 4 | +ComposerAutoloaderInita657e2f64bf98eb70db4e96bba0d4058::loadClassLoader - 2.3ms | 0us | 0us | 51.6KB | 0B | 0B | 5 | +ComposerAutoloaderInita657e2f64bf98eb70db4e96bba0d4058::/home/sylvain/dev/sf_app/vendor/composer/ClassLoader.php - 2.3ms | 1us | 1us | 51.6KB | 0B | 0B | 5 | -ComposerAutoloaderInita657e2f64bf98eb70db4e96bba0d4058::/home/sylvain/dev/sf_app/vendor/composer/ClassLoader.php - 2.3ms | 1.0ms | 1.0ms | 51.3KB | 39.4KB | 39.4KB | 4 | -ComposerAutoloaderInita657e2f64bf98eb70db4e96bba0d4058::loadClassLoader - 2.7ms | 0us | 0us | 91.5KB | 0B | 0B | 4 | +ComposerAutoloaderInita657e2f64bf98eb70db4e96bba0d4058::/home/sylvain/dev/sf_app/vendor/composer/autoload_static.php - 2.7ms | 1us | 1us | 91.5KB | 0B | 0B | 4 | -ComposerAutoloaderInita657e2f64bf98eb70db4e96bba0d4058::/home/sylvain/dev/sf_app/vendor/composer/autoload_static.php - 2.7ms | 0us | 0us | 91.2KB | 0B | 0B | 4 | +Composer\Autoload\ComposerStaticInita657e2f64bf98eb70db4e96bba0d4058::getInitializer - 2.7ms | 5us | 5us | 92.0KB | 856B | 856B | 4 | -Composer\Autoload\ComposerStaticInita657e2f64bf98eb70db4e96bba0d4058::getInitializer - 2.7ms | 0us | 0us | 92.0KB | 0B | 0B | 4 | +Composer\Autoload\ClassLoader::Composer\Autoload\{closure} - 2.7ms | 5us | 5us | 91.2KB | -856B | -856B | 4 | -Composer\Autoload\ClassLoader::Composer\Autoload\{closure} - 2.7ms | 0us | 0us | 91.2KB | 0B | 0B | 4 | +Composer\Autoload\ClassLoader::register - 2.7ms | 6us | 6us | 91.3KB | 128B | 128B | 4 | -Composer\Autoload\ClassLoader::register + 0ns | 0ns | 0ns | 0B | 0B | 0B | 1 | +/var/www/sfapp/bin/console + 111.8us | 0ns | 0ns | 1.6KB | 0B | 0B | 2 | +main + 274.2us | 0ns | 0ns | 14.9KB | 0B | 0B | 3 | +main + 275.3us | 1.0us | 1.0us | 14.9KB | 0B | 0B | 3 | -main + 278.6us | 0ns | 0ns | 14.5KB | 0B | 0B | 3 | +ComposerAutoloaderInitff0faccf08b80bfc8761e2c1e69c7292::getLoader + 298.4us | 0ns | 0ns | 15.4KB | 0B | 0B | 4 | +ComposerAutoloaderInitff0faccf08b80bfc8761e2c1e69c7292::loadClassLoader + 591.7us | 0ns | 0ns | 74.9KB | 0B | 0B | 5 | +main + 592.5us | 784ns | 784ns | 74.9KB | 0B | 0B | 5 | -main + 593.0us | 294.6us | 293.8us | 74.3KB | 59.0KB | 59.0KB | 4 | -ComposerAutoloaderInitff0faccf08b80bfc8761e2c1e69c7292::loadClassLoader + 799.5us | 0ns | 0ns | 119.1KB | 0B | 0B | 4 | +main + 800.1us | 623ns | 623ns | 119.1KB | 0B | 0B | 4 | -main + 802.7us | 0ns | 0ns | 118.7KB | 0B | 0B | 4 | +Composer\Autoload\ComposerStaticInitff0faccf08b80bfc8761e2c1e69c7292::getInitializer + 809.5us | 6.8us | 6.8us | 119.6KB | 912B | 912B | 4 | -Composer\Autoload\ComposerStaticInitff0faccf08b80bfc8761e2c1e69c7292::getInitializer + 812.6us | 0ns | 0ns | 119.7KB | 0B | 0B | 4 | +Composer\Autoload\ClassLoader::Composer\Autoload\{closure} + 820.3us | 7.8us | 7.8us | 119.8KB | 48B | 48B | 4 | -Composer\Autoload\ClassLoader::Composer\Autoload\{closure} + 822.1us | 0ns | 0ns | 118.9KB | 0B | 0B | 4 | +Composer\Autoload\ClassLoader::register + 828.7us | 6.6us | 6.6us | 119.1KB | 208B | 208B | 4 | -Composer\Autoload\ClassLoader::register ... - 126.6ms | 24.6ms | 10us | 6.1MB | 874.8KB | 488B | 4 | -Symfony\Component\Console\Application::doRun - 126.6ms | 97.2ms | 27us | 6.1MB | 4.9MB | 0B | 3 | -Symfony\Bundle\FrameworkBundle\Console\Application::doRun - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 3 | +Symfony\Component\Debug\ErrorHandler::handleFatalError - 126.6ms | 4us | 4us | 6.1MB | -12.0KB | -12.0KB | 3 | -Symfony\Component\Debug\ErrorHandler::handleFatalError - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 3 | +Monolog\Handler\AbstractHandler::__destruct - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 4 | +Symfony\Bridge\Monolog\Handler\ConsoleHandler::close - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 5 | +Monolog\Handler\AbstractHandler::close - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 5 | -Monolog\Handler\AbstractHandler::close - 126.6ms | 1us | 1us | 6.1MB | 0B | 0B | 4 | -Symfony\Bridge\Monolog\Handler\ConsoleHandler::close - 126.6ms | 3us | 2us | 6.1MB | 0B | 0B | 3 | -Monolog\Handler\AbstractHandler::__destruct - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 3 | +Monolog\Handler\AbstractHandler::__destruct - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 4 | +Monolog\Handler\AbstractHandler::close - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 4 | -Monolog\Handler\AbstractHandler::close - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 3 | -Monolog\Handler\AbstractHandler::__destruct - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 3 | +Monolog\Handler\AbstractHandler::__destruct - 126.6ms | 0us | 0us | 6.1MB | 0B | 0B | 4 | +Monolog\Handler\StreamHandler::close - 126.6ms | 2us | 2us | 6.1MB | 0B | 0B | 4 | -Monolog\Handler\StreamHandler::close - 126.6ms | 2us | 0us | 6.1MB | 0B | 0B | 3 | -Monolog\Handler\AbstractHandler::__destruct - 126.6ms | 105.6ms | 38us | 6.1MB | 5.2MB | 624B | 2 | -Symfony\Component\Console\Application::run - 126.6ms | 126.6ms | 1.0ms | 6.1MB | 6.1MB | 1.6KB | 1 | -/home/sylvain/dev/sf_app/bin/console + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 3 | +/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Traits/FilesystemCommonTrait.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 4 | +Symfony\Component\Cache\Adapter\AbstractAdapter::__destruct + 129.2ms | 190ns | 190ns | 14.6MB | 0B | 0B | 4 | -Symfony\Component\Cache\Adapter\AbstractAdapter::__destruct + 129.2ms | 853ns | 663ns | 14.6MB | 48B | 48B | 3 | -/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Traits/FilesystemCommonTrait.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 3 | +/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Adapter/AbstractAdapter.php + 129.2ms | 308ns | 308ns | 14.6MB | 48B | 48B | 3 | -/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Adapter/AbstractAdapter.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 3 | +/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Traits/FilesystemCommonTrait.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 4 | +Symfony\Component\Cache\Adapter\AbstractAdapter::__destruct + 129.2ms | 237ns | 237ns | 14.6MB | 0B | 0B | 4 | -Symfony\Component\Cache\Adapter\AbstractAdapter::__destruct + 129.2ms | 851ns | 614ns | 14.6MB | 48B | 48B | 3 | -/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Traits/FilesystemCommonTrait.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 3 | +/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Adapter/AbstractAdapter.php + 129.2ms | 154ns | 154ns | 14.6MB | 48B | 48B | 3 | -/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Adapter/AbstractAdapter.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 3 | +/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Traits/FilesystemCommonTrait.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 4 | +Symfony\Component\Cache\Adapter\AbstractAdapter::__destruct + 129.2ms | 172ns | 172ns | 14.6MB | 0B | 0B | 4 | -Symfony\Component\Cache\Adapter\AbstractAdapter::__destruct + 129.2ms | 717ns | 545ns | 14.6MB | 48B | 48B | 3 | -/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Traits/FilesystemCommonTrait.php + 129.2ms | 0ns | 0ns | 14.6MB | 0B | 0B | 3 | +/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Adapter/AbstractAdapter.php + 129.2ms | 244ns | 244ns | 14.6MB | 48B | 48B | 3 | -/var/www/sfapp/vendor/symfony/symfony/src/Symfony/Component/Cache/Adapter/AbstractAdapter.php + 129.2ms | 120.6ms | 84.5us | 14.6MB | 13.2MB | 3.1KB | 2 | -Symfony\Component\Console\Application::run + 129.2ms | 129.2ms | 134.1us | 14.6MB | 14.6MB | 2.1KB | 1 | -/var/www/sfapp/bin/console ``` - ## Credits I have found lot of inspiration and hints reading: diff --git a/assets/docs/as-fg.png b/assets/docs/as-fg.png new file mode 100644 index 0000000..ddf26c2 Binary files /dev/null and b/assets/docs/as-fg.png differ diff --git a/assets/docs/as-fp.png b/assets/docs/as-fp.png new file mode 100644 index 0000000..b1e842b Binary files /dev/null and b/assets/docs/as-fp.png differ diff --git a/assets/docs/as-ms.png b/assets/docs/as-ms.png new file mode 100644 index 0000000..6f9f336 Binary files /dev/null and b/assets/docs/as-ms.png differ diff --git a/assets/docs/as-ov.png b/assets/docs/as-ov.png new file mode 100644 index 0000000..5141e43 Binary files /dev/null and b/assets/docs/as-ov.png differ diff --git a/assets/docs/as-tl.png b/assets/docs/as-tl.png new file mode 100644 index 0000000..14adc0e Binary files /dev/null and b/assets/docs/as-tl.png differ diff --git a/assets/docs/as.png b/assets/docs/as.png new file mode 100644 index 0000000..826ffd8 Binary files /dev/null and b/assets/docs/as.png differ diff --git a/docs/cg1.png b/assets/docs/cg1.png similarity index 100% rename from docs/cg1.png rename to assets/docs/cg1.png diff --git a/assets/docs/cp-form.png b/assets/docs/cp-form.png new file mode 100644 index 0000000..c30ada6 Binary files /dev/null and b/assets/docs/cp-form.png differ diff --git a/assets/docs/cp-list1.png b/assets/docs/cp-list1.png new file mode 100644 index 0000000..ffda613 Binary files /dev/null and b/assets/docs/cp-list1.png differ diff --git a/assets/docs/cp-list2.png b/assets/docs/cp-list2.png new file mode 100644 index 0000000..adf905f Binary files /dev/null and b/assets/docs/cp-list2.png differ diff --git a/docs/fp1.gif b/assets/docs/fp1.gif similarity index 100% rename from docs/fp1.gif rename to assets/docs/fp1.gif diff --git a/docs/gte1.png b/assets/docs/gte1.png similarity index 100% rename from docs/gte1.png rename to assets/docs/gte1.png diff --git a/assets/web-ui/css/main.css b/assets/web-ui/css/main.css new file mode 100644 index 0000000..b90a0b1 --- /dev/null +++ b/assets/web-ui/css/main.css @@ -0,0 +1,184 @@ +body { + background: #023; + background: -webkit-linear-gradient(#023, #000); + background: -o-linear-gradient(#023, #000); + background: -moz-linear-gradient(#023, #000); + background: linear-gradient(#023, #000); + background-repeat: no-repeat; + background-attachment: fixed; + + font-family: monospace; + margin: 2px; + padding: 0; +} + +* { + color: #089; +} + +form#config label { + display: inline-block; + width: 300px; + margin-right: 20px; + margin-bottom: 30px; + text-align: right; + vertical-align: top; +} + +form#config em { + display: inline-block; + vertical-align: top; + width: 300px; + margin-left: 10px; + margin-bottom: 20px; +} + +form#config input { + vertical-align: top; +} + +form#config select { + margin-bottom: 10px; + background-color: #000; + width: 200px; +} + +table.data_table { + border-collapse: collapse; + border-spacing: 0; + margin: auto; + margin-top: 5px; +} + +table.data_table tr { + cursor: pointer; +} + +table.data_table th, +table.data_table td { + border: 1px solid #044; + margin: 0; + padding: 3px; +} + +table.data_table th.data_table-sort, +table.data_table th:hover { + background-color: #023; +} + +table.data_table tbody > tr:hover { + background-color: #033; +} + +table.data_table td.breakable-text { + word-break: break-all; +} + +table.data_table td > a { + display: block; + text-decoration: none; +} + +#init-report { + position: absolute; + left: 50%; +} + +#init-report > div { + position: relative; + left: -50%; + top: 200px; + border: solid 1px #0aa; + background-color: #023; + width: 400px; + height: 200px; + padding: 10px; + vertical-align: center; + text-align: center; +} + +#init-report div.progress { + display: none; + width: 100%; + height: 20px; + border: solid 1px #099; + padding: 1px; +} + +#init-report div.progress > div { + height: 100%; + background-color: #0d0; +} + +#overview, +#timeline { + cursor: -webkit-grab; + cursor:-moz-grab; +} + +#overview:active, +#timeline:active { + cursor: -webkit-grabbing; + cursor:-moz-grabbing; +} + +table.layout { + border-spacing: 0; + width: 100%; +} + +table.layout td { + padding: 0; +} + +.widget { + border: solid 1px #022; +} + +.widget:hover { + border: solid 1px #0aa; +} + +.visualization { + -webkit-touch-callout: none; + -webkit-user-select: none; + -khtml-user-select: none; + -moz-user-select: none; + -ms-user-select: none; + user-select: none; +} + +#metric-selector select { + background-color: #000; +} + +#flatprofile { + h: right; +} + +#flatprofile table { + border-collapse: collapse; + border-spacing: 0; + margin: 0; +} + +#flatprofile table th, +#flatprofile table td { + border: 1px solid #044; + margin: 0; + padding-left: 2px; + padding-right: 2px; +} + +#flatprofile table th.sortable { + cursor: pointer; +} + +#flatprofile table th.sort, +#flatprofile table th.sortable:hover { + background-color: #023; +} + +#flatprofile table td { + text-align: right; +} diff --git a/assets/web-ui/index.html b/assets/web-ui/index.html new file mode 100644 index 0000000..bd00aec --- /dev/null +++ b/assets/web-ui/index.html @@ -0,0 +1,275 @@ + + + + + SPX Control Panel + + + + +

SPX Control Panel

+ +
+
+ Configuration +
+
+
+ +
+ + + + + + + + + + + diff --git a/assets/web-ui/js/dataTable.js b/assets/web-ui/js/dataTable.js new file mode 100644 index 0000000..60b336c --- /dev/null +++ b/assets/web-ui/js/dataTable.js @@ -0,0 +1,68 @@ + +export function makeDataTable(containerId, options, rows) { + let sort_col = 0; + let sort_dir = -1; + + function getColumnValue(accessor, row) { + if ($.type(accessor) === 'function') { + return accessor(row); + } + + return row[accessor]; + } + + let container = $('#' + containerId); + let render = () => { + let html = ''; + + for (let i = 0; i < options.columns.length; i++) { + let column = options.columns[i]; + html += ``; + } + + html += ''; + + rows.sort((a, b) => { + a = getColumnValue(options.columns[sort_col].value, a); + b = getColumnValue(options.columns[sort_col].value, b); + + return (a < b ? -1 : (a > b)) * sort_dir; + }); + + for (let row of rows) { + let url = options.makeRowUrl ? options.makeRowUrl(row) : null; + html += ''; + for (let column of options.columns) { + let value = getColumnValue(column.value, row); + if (column.format) { + value = column.format(value); + } + + if (url) { + value = `${value}`; + } + + html += ``; + } + + html += ''; + } + + html += '
${column.label}
${value}
'; + + container.append(html); + container.find('th').click(e => { + let current = $(e.target).index(); + if (sort_col == current) { + sort_dir *= -1; + } + + sort_col = current; + + container.empty(); + render(); + }); + } + + render(); +} diff --git a/assets/web-ui/js/fmt.js b/assets/web-ui/js/fmt.js new file mode 100644 index 0000000..6c8179d --- /dev/null +++ b/assets/web-ui/js/fmt.js @@ -0,0 +1,76 @@ + +import {round} from './math.js'; + +function lpad(str, len, char) { + str = str + ''; + let d = len - str.length; + if (d <= 0) { + return str; + } + + return char.repeat(d) + str; +} + +export function date(d) { + return d.getFullYear() + + '-' + lpad(d.getMonth() + 1, 2, '0') + + '-' + lpad(d.getDate(), 2, '0') + + ' ' + lpad(d.getHours(), 2, '0') + + ':' + lpad(d.getMinutes(), 2, '0') + + ':' + lpad(d.getSeconds(), 2, '0') + ; +} + +export function quantity(n) { + if (n > 1000 * 1000 * 1000) { + return round(n / (1000 * 1000 * 1000), 2).toFixed(2) + 'G'; + } + + if (n > 1000 * 1000) { + return round(n / (1000 * 1000), 2).toFixed(2) + 'M'; + } + + if (n > 1000) { + return round(n / 1000, 2).toFixed(2) + 'K'; + } + + return round(n, 0); +} + +export function pct(n) { + return round(n * 100, 2).toFixed(2) + '%'; +} + +export function time(n) { + if (n > 1000 * 1000 * 1000) { + return round(n / (1000 * 1000 * 1000), 2).toFixed(2) + 's'; + } + + if (n > 1000 * 1000) { + return round(n / (1000 * 1000), 2).toFixed(2) + 'ms'; + } + + if (n > 1000) { + return round(n / (1000), 2).toFixed(2) + 'us'; + } + + return round(n, 0) + 'ns'; +} + +export function memory(n) { + const abs = Math.abs(n); + + if (abs > (1 << 30)) { + return round(n / (1 << 30), 2).toFixed(2) + 'GB'; + } + + if (abs > (1 << 20)) { + return round(n / (1 << 20), 2).toFixed(2) + 'MB'; + } + + if (abs > (1 << 10)) { + return round(n / (1 << 10), 2).toFixed(2) + 'KB'; + } + + return round(n, 0) + 'B'; +} diff --git a/assets/web-ui/js/math.js b/assets/web-ui/js/math.js new file mode 100644 index 0000000..4aa1b3a --- /dev/null +++ b/assets/web-ui/js/math.js @@ -0,0 +1,179 @@ + +export function round(n, d) { + const scale = Math.pow(10, d || 0); + + return Math.round(n * scale) / scale; +} + +export function bound(a, low, up) { + return Math.max(low || 0, Math.min(a, up || 1)); +} + +export function lerp(a, b, dist) { + dist = bound(dist); + + return a * (1 - dist) + b * dist; +} + +export function lerpDist(a, b, value) { + return (value - a) / (b - a); +} + +export class Vec3 { + + constructor(x, y, z) { + this.x = x; + this.y = y; + this.z = z; + } + + copy() { + return new Vec3( + this.x, + this.y, + this.z + ); + } + + bound(low, up) { + bound(this.x, low, up); + bound(this.y, low, up); + bound(this.z, low, up); + + return this; + } + + toHTMLColor() { + const c = this.copy().bound(); + + return 'rgb(' + [ + parseInt(c.x * 255), + parseInt(c.y * 255), + parseInt(c.z * 255), + ].join(',') + ')'; + } + + static createFromRGB888(r, g, b) { + const v = new Vec3( + r / 255, + g / 255, + b / 255, + ); + + return v.bound(); + } + + static lerp(a, b, dist) { + return new Vec3( + lerp(a.x, b.x, dist), + lerp(a.y, b.y, dist), + lerp(a.z, b.z, dist) + ); + } + + static lerpPath(vectors, dist) { + dist = bound(dist); + + const span = 1 / (vectors.length - 1); + const firstIdx = bound(parseInt(dist / span), 0, vectors.length - 2); + + return this.lerp( + vectors[firstIdx], + vectors[firstIdx + 1], + (dist - firstIdx * span) / span + ); + } +} + +export class Range { + + constructor(begin, end) { + if (begin > end) { + throw new Error('Invalid range: ' + begin + ' ' + end); + } + + this.begin = begin; + this.end = end; + } + + copy() { + return new Range(this.begin, this.end); + } + + length() { + return this.end - this.begin; + } + + center() { + return (this.begin + this.end) / 2; + } + + lerp(dist) { + return lerp(this.begin, this.end, dist); + } + + lerpDist(value) { + return lerpDist(this.begin, this.end, value); + } + + intersection(other) { + if (!this.overlaps(other)) { + throw new Error('Ranges do not overlap'); + } + + return new Range( + Math.max(this.begin, other.begin), + Math.min(this.end, other.end) + ); + } + + subRange(ratio, num) { + const width = ratio * this.length(); + + return new Range( + Math.max(this.begin, this.begin + width * num), + Math.min(this.end, this.begin + width * (num + 1)) + ); + } + + scale(factor) { + this.begin *= factor; + this.end *= factor; + + return this; + } + + shift(dist) { + this.begin += dist; + this.end += dist; + + return this; + } + + bound(low, up) { + low = low || 0; + up = up || 1; + + this.begin = bound(this.begin, low, up); + this.end = bound(this.end, low, up); + + if (this.begin > this.end) { + this.begin = low; + this.end = up; + } + + return this; + } + + contains(other) { + return this.begin <= other.begin && other.end <= this.end; + } + + isContainedBy(other) { + return other.contains(this); + } + + overlaps(other) { + return !(this.end < other.begin || other.end < this.begin); + } +} diff --git a/assets/web-ui/js/profileData.js b/assets/web-ui/js/profileData.js new file mode 100644 index 0000000..6eed329 --- /dev/null +++ b/assets/web-ui/js/profileData.js @@ -0,0 +1,1212 @@ +import * as utils from './utils.js'; +import * as fmt from './fmt.js'; +import * as math from './math.js'; + +class MetricValues { + + static createFromMetricsAndValue(metrics, value) { + let values = {}; + for (let m of metrics) { + values[m] = value; + } + + return new MetricValues(values); + } + + static lerpByTime(a, b, time) { + if (a.values['wt'] == b.values['wt']) { + return a.copy(); + } + + const dist = (time - a.values['wt']) / (b.values['wt'] - a.values['wt']); + + let values = {}; + for (let m in a.values) { + values[m] = math.lerp( + a.values[m], + b.values[m], + dist + ); + } + + return new MetricValues(values); + } + + constructor(values) { + this.values = values; + } + + copy() { + let copy = {}; + for (let i in this.values) { + copy[i] = this.values[i]; + } + + return new MetricValues(copy); + } + + getMetrics() { + return Object.keys(this.values); + } + + getValue(metric) { + return this.values[metric]; + } + + setValue(metric, value) { + this.values[metric] = value; + } + + set(value) { + for (let i in this.values) { + this.values[i] = value; + } + + return this; + } + + add(other) { + for (let i in this.values) { + this.values[i] += other.values[i]; + } + + return this; + } + + sub(other) { + for (let i in this.values) { + this.values[i] -= other.values[i]; + } + + return this; + } + + min(other) { + for (let i in this.values) { + this.values[i] = Math.min(this.values[i], other.values[i]); + } + + return this; + } + + max(other) { + for (let i in this.values) { + this.values[i] = Math.max(this.values[i], other.values[i]); + } + + return this; + } +} + +class CallListEntry { + + constructor(list, idx) { + if (idx < 0 || idx >= list.getSize()) { + throw new Error('Out of bound index: ' + idx); + } + + this.list = list; + this.idx = idx; + this.elemOffset = idx * this.list.elemSize; + } + + getIdx() { + return this.idx; + } + + getFunctionIdx() { + return this.list.array.getElementFieldValue(this.idx, 'functionIdx'); + } + + getFunctionName() { + return this.list.functionNames[this.getFunctionIdx()]; + } + + getMetrics() { + return this.list.metrics; + } + + getMetricValue(type, metric) { + return this.list.array.getElementFieldValue(this.idx, type + '_' + metric); + } + + getMetricValues(type) { + let values = {}; + for (let metric of this.list.metrics) { + values[metric] = this.getMetricValue(type, metric); + } + + return new MetricValues(values); + } + + getStart(metric) { + return this.getMetricValue('start', metric); + } + + getEnd(metric) { + return this.getMetricValue('end', metric); + } + + getInc(metric) { + return this.getEnd(metric) - this.getStart(metric); + } + + getExc(metric) { + return this.getMetricValue('exc', metric); + } + + getTimeRange() { + return new math.Range(this.getStart('wt'), this.getEnd('wt')); + } + + getParent() { + const parentIdx = this.list.array.getElementFieldValue(this.idx, 'parentIdx'); + if (parentIdx < 0) { + return null; + } + + return this.list.getCall(parentIdx); + } + + getAncestors() { + const ancestors = []; + + let parent = this.getParent(); + while (parent != null) { + ancestors.push(parent); + parent = parent.getParent(); + } + + return ancestors; + } + + getStack() { + const stack = this.getAncestors().reverse(); + stack.push(this); + + return stack; + } + + getDepth() { + let parentIdx = this.list.array.getElementFieldValue(this.idx, 'parentIdx'); + let depth = 0; + while (parentIdx >= 0) { + parentIdx = this.list.array.getElementFieldValue(parentIdx, 'parentIdx'); + depth++; + } + + return depth; + } + + getCycleDepth() { + const functionIdx = this.getFunctionIdx(); + let parentIdx = this.list.array.getElementFieldValue(this.idx, 'parentIdx'); + + let cycleDepth = 0; + while (parentIdx >= 0) { + const parentFunctionIdx = this.list.array.getElementFieldValue(parentIdx, 'functionIdx'); + if (functionIdx == parentFunctionIdx) { + cycleDepth++; + } + + parentIdx = this.list.array.getElementFieldValue(parentIdx, 'parentIdx'); + } + + return cycleDepth; + } +} + +class CallList { + + constructor(size, functionCount, metrics) { + this.metrics = metrics; + this.functionNames = Array(functionCount).fill("n/a"); + + this.metricOffsets = {}; + for (let i = 0; i < this.metrics.length; i++) { + this.metricOffsets[this.metrics[i]] = i; + } + + // FIXME use float32 to save space ? + const structure = { + functionIdx: 'int32', + parentIdx: 'int32', + }; + + for (let metric of this.metrics) { + structure['start_' + metric] = 'float64'; + structure['end_' + metric] = 'float64'; + structure['exc_' + metric] = 'float64'; + } + + this.array = new utils.PackedRecordArray(structure, size); + } + + getSize() { + return this.array.size; + } + + getMetrics() { + return this.metrics; + } + + setRawCallData(idx, functionNameIdx, parentIdx, start, end, exc) { + const elt = { + functionIdx: functionNameIdx, + parentIdx: parentIdx, + }; + + for (let i = 0; i < this.metrics.length; i++) { + const metric = this.metrics[i]; + + elt['start_' + metric] = start[i]; + elt['end_' + metric] = end[i]; + elt['exc_' + metric] = exc[i]; + } + + this.array.setElement(idx, elt); + + return this; + } + + getCall(idx) { + return new CallListEntry(this, idx); + } + + setFunctionName(idx, functionName) { + this.functionNames[idx] = functionName; + + return this; + } +} + +class MetricValuesList { + + constructor(size, metrics) { + this.metrics = metrics; + + const structure = {}; + for (let metric of this.metrics) { + structure[metric] = 'float64'; + } + + this.array = new utils.PackedRecordArray(structure, size); + } + + setRawMetricValuesData(idx, rawMetricValuesData) { + const elt = {}; + + for (let i = 0; i < this.metrics.length; i++) { + const metric = this.metrics[i]; + + elt[metric] = rawMetricValuesData[i]; + } + + this.array.setElement(idx, elt); + } + + getMetricValues(time) { + const nearestIdx = this._findNearestIdx(time); + const nearestRawMetricValues = this.array.getElement(nearestIdx); + + if (nearestRawMetricValues['wt'] == time) { + return new MetricValues(nearestRawMetricValues); + } + + let lowerRawMetricValues = null; + let upperRawMetricValues = null; + + if (nearestRawMetricValues['wt'] < time) { + lowerRawMetricValues = nearestRawMetricValues; + upperRawMetricValues = this.array.getElement(nearestIdx + 1); + } else { + lowerRawMetricValues = this.array.getElement(nearestIdx - 1); + upperRawMetricValues = nearestRawMetricValues; + } + + return MetricValues.lerpByTime( + new MetricValues(lowerRawMetricValues), + new MetricValues(upperRawMetricValues), + time + ); + } + + _findNearestIdx(time, range) { + range = range || new math.Range(0, this.array.getSize()); + + if (range.length() == 1) { + return range.begin; + } + + const center = Math.floor(range.center()); + const centerTime = this.array.getElementFieldValue(center, 'wt'); + + if (time < centerTime) { + return this._findNearestIdx(time, new math.Range(range.begin, center)); + } + + if (time > centerTime) { + return this._findNearestIdx(time, new math.Range(center, range.end)); + } + + return center; + } +} + +class Stats { + + constructor(metrics) { + this.min = MetricValues.createFromMetricsAndValue(metrics, Number.MAX_VALUE); + this.max = MetricValues.createFromMetricsAndValue(metrics, -Number.MAX_VALUE); + this.callMin = MetricValues.createFromMetricsAndValue(metrics, Number.MAX_VALUE); + this.callMax = MetricValues.createFromMetricsAndValue(metrics, -Number.MAX_VALUE); + } + + getMin(metric) { + return this.min.getValue(metric); + } + + getMax(metric) { + return this.max.getValue(metric); + } + + getRange(metric) { + return new math.Range( + this.getMin(metric), + this.getMax(metric) + ); + } + + getCallMin(metric) { + return this.callMin.getValue(metric); + } + + getCallMax(metric) { + return this.callMax.getValue(metric); + } + + getCallRange(metric) { + return new math.Range( + this.getCallMin(metric), + this.getCallMax(metric) + ); + } + + merge(other) { + this.min.min(other.min); + this.max.max(other.max); + this.callMin.min(other.callMin); + this.callMax.max(other.callMax); + + return this; + } + + mergeMetricValue(metric, value) { + this.min.setValue(metric, Math.min( + this.min.getValue(metric), + value + )); + + this.max.setValue(metric, Math.max( + this.max.getValue(metric), + value + )); + } + + mergeCallMetricValue(metric, value) { + this.callMin.setValue(metric, Math.min( + this.callMin.getValue(metric), + value + )); + + this.callMax.setValue(metric, Math.max( + this.callMax.getValue(metric), + value + )); + } +} + +class FunctionsStats { + + constructor(callRefs, callList, lowerBound, upperBound) { + this.functionsStats = new Map(); + + callRefs = callRefs || []; + for (let callRef of callRefs) { + let call = callList.getCall(callRef); + let stats = this.functionsStats.get(call.getFunctionIdx()); + if (!stats) { + stats = { + functionName: call.getFunctionName(), + maxCycleDepth: 0, + called: 0, + inc: MetricValues.createFromMetricsAndValue(call.getMetrics(), 0), + exc: MetricValues.createFromMetricsAndValue(call.getMetrics(), 0), + }; + + this.functionsStats.set(call.getFunctionIdx(), stats); + } + + stats.called++; + let cycleDepth = call.getCycleDepth(); + stats.maxCycleDepth = Math.max(stats.maxCycleDepth, cycleDepth); + if (cycleDepth > 0) { + continue; + } + + let truncated = false; + + let start = call.getMetricValues('start'); + if (lowerBound && lowerBound.getValue('wt') > start.getValue('wt')) { + start = lowerBound; + truncated = true; + } + + let end = call.getMetricValues('end'); + if (upperBound && upperBound.getValue('wt') < end.getValue('wt')) { + end = upperBound; + truncated = true; + } + + stats.inc.add(end.copy().sub(start)); + if (!truncated) { + stats.exc.add(call.getMetricValues('exc')); + } + } + } + + getValues() { + return Array.from(this.functionsStats.values()); + } + + merge(other) { + for (let key of other.functionsStats.keys()) { + let a = this.functionsStats.get(key); + let b = other.functionsStats.get(key); + + if (!a) { + this.functionsStats.set(key, { + functionName: b.functionName, + maxCycleDepth: b.maxCycleDepth, + called: b.called, + inc: b.inc.copy(), + exc: b.exc.copy(), + }); + + continue; + } + + a.called += b.called; + a.maxCycleDepth = Math.max(a.maxCycleDepth, b.maxCycleDepth); + + a.inc.add(b.inc); + a.exc.add(b.exc); + } + } +} + +class CallGraphStatsNode { + + constructor(functionName, metrics) { + this.functionName = functionName; + this.parent = null; + this.children = {}; + this.minTime = Number.MAX_VALUE; + this.called = 0; + this.inc = MetricValues.createFromMetricsAndValue(metrics, 0); + } + + getFunctionName() { + return this.functionName; + } + + getCalled() { + return this.called; + } + + getInc() { + return this.inc; + } + + getParent() { + return this.parent; + } + + getChildren() { + return Object + .keys(this.children) + .map(k => this.children[k]) + .sort((a, b) => a.minTime - b.minTime) + ; + } + + getDepth() { + let depth = 0; + let parent = this.getParent(); + while (parent != null) { + depth++; + parent = parent.getParent(); + } + + return depth; + } + + getMinInc() { + const minInc = this.inc.copy(); + for (let i in this.children) { + minInc.min(this.children[i].getMinInc()); + } + + return minInc; + } + + getMaxCumInc(minInc) { + minInc = minInc || this.getMinInc(); + let maxCumInc = null; + for (let i in this.children) { + if (maxCumInc == null) { + maxCumInc = this.children[i].getMaxCumInc(minInc).copy(); + } else { + maxCumInc.add(this.children[i].getMaxCumInc(minInc)); + } + } + + if (maxCumInc == null) { + maxCumInc = this.inc.copy().set(-Number.MAX_VALUE); + } + + return maxCumInc.max(this.inc.copy().sub(minInc)); + } + + addChild(node) { + node.parent = this; + this.children[node.functionName] = node; + + return this; + } + + addCallStats(start, end) { + this.minTime = Math.min(this.minTime, start.getValue('wt')); + this.called++; + this.inc.add(end.copy().sub(start)); + + return this; + } + + merge(other) { + this.called += other.called; + this.inc.add(other.inc); + this.minTime = Math.min(this.minTime, other.minTime); + + for (let i in other.children) { + if (!(i in this.children)) { + this.addChild(new CallGraphStatsNode( + other.children[i].getFunctionName(), + other.children[i].getInc().getMetrics() + )); + } + + this.children[i].merge(other.children[i]); + } + + return this; + } + + prune(minDuration) { + for (let i in this.children) { + const child = this.children[i]; + + if (child.called > 0 && child.inc.getValue('wt') < minDuration) { + delete this.children[i]; + + continue; + } + + child.prune(minDuration); + } + + return this; + } +} + +class CallGraphStats { + + constructor(callRefs, callList, lowerBound, upperBound) { + this.root = new CallGraphStatsNode(null, callList.getMetrics()); + this.root.called = 1; + + callRefs = callRefs || []; + for (let callRef of callRefs) { + const call = callList.getCall(callRef); + const stack = call.getStack(); + + let node = this.root; + for (let i = 0; i < stack.length; i++) { + const functionName = stack[i].getFunctionName(); + let child = node.children[functionName]; + if (!child) { + child = new CallGraphStatsNode(functionName, callList.getMetrics()); + node.addChild(child); + } + + node = child; + } + + let start = call.getMetricValues('start'); + if (lowerBound && lowerBound.getValue('wt') > start.getValue('wt')) { + start = lowerBound; + } + + let end = call.getMetricValues('end'); + if (upperBound && upperBound.getValue('wt') < end.getValue('wt')) { + end = upperBound; + } + + node.addCallStats(start, end); + if (node.getDepth() == 1) { + node.getParent().getInc().add( + end.copy().sub(start) + ); + } + } + } + + getRoot() { + return this.root; + } + + merge(other) { + this.root.merge(other.root); + + return this; + } + + prune(minDuration) { + this.root.prune(minDuration); + + return this; + } +} + +class CallRangeTree { + + constructor(range, callList, metricValuesList) { + this.range = range; + this.callList = callList; + this.metricValuesList = metricValuesList; + this.callRefs = []; + this.children = []; + this.functionsStats = null; + this.callGraphStats = null; + } + + getNodeCount() { + let nodeCount = 0; + for (const child of this.children) { + nodeCount += child.getNodeCount(); + } + + return 1 + nodeCount; + } + + getMaxDepth() { + let maxDepth = 0; + for (const child of this.children) { + maxDepth = Math.max(maxDepth, child.getMaxDepth()); + } + + return maxDepth + 1; + } + + getFunctionsStats(range, lowerBound, upperBound) { + if (!this.range.overlaps(range)) { + return new FunctionsStats([]); + } + + if (this.range.isContainedBy(range)) { + return this.functionsStats; + } + + let callRefs = []; + for (let callRef of this.callRefs) { + let callTimeRange = this.callList.getCall(callRef).getTimeRange(); + if (callTimeRange.overlaps(range)) { + callRefs.push(callRef); + } + } + + if (lowerBound == null && this.range.begin < range.begin) { + lowerBound = this.metricValuesList.getMetricValues(range.begin); + } + + if (upperBound == null && this.range.end > range.end) { + upperBound = this.metricValuesList.getMetricValues(range.end); + } + + let functionsStats = new FunctionsStats( + callRefs, + this.callList, + lowerBound, + upperBound + ); + + for (let child of this.children) { + functionsStats.merge(child.getFunctionsStats(range, lowerBound, upperBound)); + } + + return functionsStats; + } + + getCallGraphStats(range, lowerBound, upperBound) { + if (!this.range.overlaps(range)) { + return new CallGraphStats([], this.callList); + } + + if (this.range.isContainedBy(range)) { + return this.callGraphStats; + } + + let callRefs = []; + for (let callRef of this.callRefs) { + let callTimeRange = this.callList.getCall(callRef).getTimeRange(); + if (callTimeRange.overlaps(range)) { + callRefs.push(callRef); + } + } + + if (lowerBound == null && this.range.begin < range.begin) { + lowerBound = this.metricValuesList.getMetricValues(range.begin); + } + + if (upperBound == null && this.range.end > range.end) { + upperBound = this.metricValuesList.getMetricValues(range.end); + } + + let callGraphStats = new CallGraphStats( + callRefs, + this.callList, + lowerBound, + upperBound + ); + + for (let child of this.children) { + callGraphStats.merge(child.getCallGraphStats(range, lowerBound, upperBound)); + } + + return callGraphStats; + } + + getCallRefs(range, minDuration, callRefs) { + if (this.range.length() < minDuration) { + return []; + } + + if (!this.range.overlaps(range)) { + return []; + } + + if (callRefs === undefined) { + callRefs = []; + } + + for (const callRef of this.callRefs) { + const callTimeRange = this.callList.getCall(callRef).getTimeRange(); + if (callTimeRange.length() < minDuration) { + // since calls are sorted + break; + } + + if (!callTimeRange.overlaps(range)) { + continue; + } + + callRefs.push(callRef); + } + + for (const child of this.children) { + child.getCallRefs(range, minDuration, callRefs); + } + + return callRefs; + } + + static buildAsync(range, callRefs, callList, metricValuesList, progress, done) { + let tree = new CallRangeTree(range, callList, metricValuesList); + + let lRange = tree.range.subRange(0.5, 0); + let rRange = tree.range.subRange(0.5, 1); + + let lCallRefs = []; + let rCallRefs = []; + + if (!callRefs) { + callRefs = Array(callList.getSize()); + for (let i = 0; i < callRefs.length; i++) { + callRefs[i] = i; + } + } + + for (let callRef of callRefs) { + let callTimeRange = callList.getCall(callRef).getTimeRange(); + + if (!tree.range.contains(callTimeRange)) { + continue; + } + + if (lRange.contains(callTimeRange)) { + lCallRefs.push(callRef); + + continue; + } + + if (rRange.contains(callTimeRange)) { + rCallRefs.push(callRef); + + continue; + } + + tree.callRefs.push(callRef); + } + + let minCallsPerNode = 500; + + if (lCallRefs.length < minCallsPerNode) { + tree.callRefs = tree.callRefs.concat(lCallRefs); + lCallRefs = []; + } + + if (rCallRefs.length < minCallsPerNode) { + tree.callRefs = tree.callRefs.concat(rCallRefs); + rCallRefs = []; + } + + tree.callRefs.sort((a, b) => { + a = callList.getCall(a).getTimeRange().length(); + b = callList.getCall(b).getTimeRange().length(); + + // N.B. "b - a" does not work on Chromium 62.0.3202.94 !!! + + if (a == b) { + return 0; + } + + return a > b ? -1 : 1; + }); + + tree.functionsStats = new FunctionsStats(tree.callRefs, callList); + tree.callGraphStats = new CallGraphStats(tree.callRefs, callList); + + utils.processCallChain([ + next => { + progress(tree.callRefs.length); + next(); + }, + next => { + if (lCallRefs.length == 0) { + next(); + + return; + } + + tree.children.push(CallRangeTree.buildAsync( + lRange, + lCallRefs, + callList, + metricValuesList, + progress, + child => { + tree.functionsStats.merge(child.functionsStats); + tree.callGraphStats.merge(child.callGraphStats); + next(); + } + )); + }, + next => { + if (rCallRefs.length == 0) { + next(); + + return; + } + + tree.children.push(CallRangeTree.buildAsync( + rRange, + rCallRefs, + callList, + metricValuesList, + progress, + child => { + tree.functionsStats.merge(child.functionsStats); + tree.callGraphStats.merge(child.callGraphStats); + next(); + } + )); + }, + () => { + // prune calls < 1/150th of node range as memory / accuracy trade-off + // FIXME /!\ this should be tunable, pruning on time basis only could broke accuracy on other metrics + // FIXME /!\ pruning appears to cause popping noise in flamegraph view + tree.callGraphStats.prune(range.length() / 150); + done(tree); + } + ], callRefs.length >= 5000, 0); + + return tree; + } +} + +class ProfileData { + + constructor(metricsInfo, metadata, stats, callList, metricValuesList, callRangeTree) { + console.log('tree', callRangeTree.getMaxDepth(), callRangeTree.getNodeCount(), callList.getSize()); + this.metricsInfo = metricsInfo; + this.metadata = metadata; + this.stats = stats; + this.callList = callList; + this.metricValuesList = metricValuesList; + this.callRangeTree = callRangeTree; + } + + getMetricKeys() { + return Object.keys(this.metricsInfo); + } + + getMetricInfo(metric) { + for (let info of this.metricsInfo) { + if (info.key == metric) { + return info; + } + } + + throw new Error('Unknown metric: ' + key); + } + + getMetricFormatter(metric) { + switch (this.getMetricInfo(metric).type) { + case 'time': + return fmt.time; + + case 'memory': + return fmt.memory; + + default: + return fmt.quantity; + } + } + + isReleasableMetric(metric) { + return this.getMetricInfo(metric).releasable; + } + + getMetadata() { + return this.metadata; + } + + getStats() { + return this.stats; + } + + getWallTime() { + return this.stats.getMax('wt'); + } + + getTimeRange() { + return new math.Range( + 0, + this.getWallTime() + ); + } + + getFunctionsStats(range) { + console.time('getFunctionsStats'); + + const functionsStats = this + .callRangeTree + .getFunctionsStats(range) + .getValues() + ; + + console.timeEnd('getFunctionsStats'); + + return functionsStats; + } + + getCall(idx) { + return this.callList.getCall(idx); + } + + getCalls(range, minDuration) { + console.time('getCalls'); + const callRefs = this.callRangeTree.getCallRefs( + range, + minDuration + ); + + let calls = []; + for (let callRef of callRefs) { + calls.push(this.callList.getCall(callRef)); + } + + console.timeEnd('getCalls'); + + return calls; + } + + getCallGraphStats(range) { + console.time('getCallGraphStats'); + + const callGraphStats = this.callRangeTree.getCallGraphStats(range); + + console.timeEnd('getCallGraphStats'); + + return callGraphStats; + } + + getMetricValues(time) { + return this.metricValuesList.getMetricValues(time); + } +} + +export class ProfileDataBuilder { + + constructor(metricsInfo) { + this.metricsInfo = metricsInfo; + } + + setMetadata(metadata) { + this.metadata = metadata; + this.metrics = metadata.enabled_metrics; + this.stats = new Stats(this.metrics); + + this.totalCallCount = metadata.recorded_call_count; + this.currentCallCount = 0; + + this.callList = new CallList( + metadata.recorded_call_count, + metadata.called_function_count, + this.metrics + ); + + this.metricValuesList = new MetricValuesList( + metadata.recorded_call_count * 2, + this.metrics + ); + + this.stack = []; + this.eventCount = 0; + this.callCount = 0; + } + + getTotalCallCount() { + return this.totalCallCount; + } + + getCurrentCallCount() { + return this.currentCallCount; + } + + addEvent(event) { + if (event[1]) { + this.stack.push({ + idx: this.callCount++, + startEvent: event, + startEventIdx: this.eventCount++, + fnIdx: event[0], + parent: this.stack.length > 0 ? this.stack[this.stack.length - 1] : null, + start: Array(this.metrics.length).fill(0), + end: Array(this.metrics.length).fill(0), + exc: Array(this.metrics.length).fill(0), + children: Array(this.metrics.length).fill(0), + }); + + return; + } + + const frame = this.stack.pop(); + + frame.endEventIdx = this.eventCount++; + + for (let j = 0; j < this.metrics.length; j++) { + const m = this.metrics[j]; + frame.start[j] = frame.startEvent[2 + j]; + frame.end[j] = event[2 + j]; + + this.stats.mergeMetricValue(m, frame.start[j]); + this.stats.mergeMetricValue(m, frame.end[j]); + this.stats.mergeCallMetricValue(m, frame.end[j] - frame.start[j]); + } + + this.metricValuesList.setRawMetricValuesData(frame.startEventIdx, frame.start); + this.metricValuesList.setRawMetricValuesData(frame.endEventIdx, frame.end); + + for (let j = 0; j < this.metrics.length; j++) { + frame.exc[j] = frame.end[j] - frame.start[j]; + if (j in frame.children) { + frame.exc[j] -= frame.children[j]; + } + } + + if (this.stack.length > 0) { + let parent = this.stack[this.stack.length - 1]; + for (let j = 0; j < this.metrics.length; j++) { + parent.children[j] += frame.end[j] - frame.start[j]; + } + + for (let k = this.stack.length - 1; k >= 0; k--) { + if (this.stack[k].fnIdx == frame.fnIdx) { + for (let j = 0; j < this.metrics.length; j++) { + this.stack[k].children[j] -= frame.exc[j]; + } + + break; + } + } + } + + this.currentCallCount++; + this.callList.setRawCallData( + frame.idx, + frame.fnIdx, + frame.parent != null ? frame.parent.idx : -1, + frame.start, + frame.end, + frame.exc + ); + } + + setFunctionName(idx, name) { + this.callList.setFunctionName(idx, name); + } + + buildCallRangeTree(setProgress) { + return new Promise(resolve => { + let totalInserted = 0; + console.time('Call range tree building'); + CallRangeTree.buildAsync( + new math.Range(0, this.stats.getMax('wt')), + null, + this.callList, + this.metricValuesList, + inserted => { + totalInserted += inserted; + setProgress(totalInserted, this.callList.getSize()); + }, + callRangeTree => { + console.timeEnd('Call range tree building'); + this.callRangeTree = callRangeTree; + resolve(); + } + ); + }); + } + + getProfileData() { + return new ProfileData( + this.metricsInfo, + this.metadata, + this.stats, + this.callList, + this.metricValuesList, + this.callRangeTree + ); + } +} diff --git a/assets/web-ui/js/svg.js b/assets/web-ui/js/svg.js new file mode 100644 index 0000000..9f760fd --- /dev/null +++ b/assets/web-ui/js/svg.js @@ -0,0 +1,45 @@ + +export function createNode(name, attributes, builder) { + let node = document.createElementNS("http://www.w3.org/2000/svg", name); + for (let k in attributes || {}) { + node.setAttribute(k, attributes[k]); + } + + if (builder) { + builder(node); + } + + return node; +} + +export class NodePool { + + constructor(name) { + this.name = name; + this.nodes = []; + this.top = 0; + } + + acquire(attributes, builder) { + if (this.nodes.length == this.top) { + this.nodes.push(createNode(this.name)); + } + + let node = this.nodes[this.top]; + this.top++; + + for (let k in attributes || {}) { + node.setAttribute(k, attributes[k]); + } + + if (builder) { + builder(node); + } + + return node; + } + + releaseAll() { + this.top = 0; + } +} diff --git a/assets/web-ui/js/utils.js b/assets/web-ui/js/utils.js new file mode 100644 index 0000000..aeaf01e --- /dev/null +++ b/assets/web-ui/js/utils.js @@ -0,0 +1,206 @@ +import * as math from './math.js'; + +export function getCookieVar(name) { + let m = document.cookie.match(new RegExp('(^|\\b)' + name + '=([^;]+)')); + + return m ? m[2] : null; +} + +export function setCookieVar(name, value) { + document.cookie = name + '=' + value + '; expires=Thu, 31 Dec 2037 23:59:59 UTC; path=/'; +} + +export function truncateFunctionName(str, max) { + if (str.length < max) { + return str; + } + + return str.slice(0, max / 2 - 1) + '…' + str.slice(-max / 2); +} + +function process(func, async, delay) { + if (async || false) { + setTimeout(func, delay || 0); + } else { + func(); + } +} + +export function processPipeline(calls, async, delay) { + calls = calls.slice(0); + calls.reverse(); + let ret; + + function makeNextCall() { + if (calls.length == 0) { + return; + } + + let call = calls.pop(); + ret = call(ret); + + if (calls.length > 0) { + process(makeNextCall, async, delay); + } + } + + process(makeNextCall, async, 0); +} + +export function processCallChain(calls, async, delay) { + calls = calls.slice(0); + calls.reverse(); + + function makeNextCall() { + if (calls.length == 0) { + return; + } + + let call = calls.pop(); + + process(() => { + call(makeNextCall); + }, async, delay || 0); + } + + makeNextCall(); +} + +export function processChunksAsync(from, to, chunkSize, chunkProcessor, done, delay) { + if (chunkSize < 1) { + chunkSize = chunkSize * (to - from); + } + + chunkSize = math.bound(Math.round(chunkSize), 1, to - from); + + let chunks = []; + + while (1) { + chunks.push([from, Math.min(to, from + chunkSize)]); + if (from + chunkSize >= to) { + break; + } + + from += chunkSize; + } + + chunks.reverse(); + + function processChunk() { + if (chunks.length == 0) { + done(); + + return; + } + + let chunk = chunks.pop(); + chunkProcessor(chunk[0], chunk[1]); + setTimeout(processChunk, delay || 0); + } + + setTimeout(processChunk, 0); +} + +export class PackedRecordArray { + + constructor(fields, size) { + this.typesInfo = { + 'int8': { + arrayType: Int8Array, + }, + 'int32': { + arrayType: Int32Array, + }, + 'float32': { + arrayType: Float32Array, + }, + 'float64': { + arrayType: Float64Array, + }, + }; + + this.fields = []; + this.elemSize = 0; + for (let fieldName in fields) { + const type = fields[fieldName]; + if (!(type in this.typesInfo)) { + throw new Error('Unsupported type: ' + type); + } + + const typeInfo = this.typesInfo[type]; + this.fields.push({ + name: fieldName, + typeInfo: typeInfo, + }); + + this.elemSize += typeInfo.arrayType.BYTES_PER_ELEMENT; + } + + this.fields.sort( + (a, b) => b.typeInfo.arrayType.BYTES_PER_ELEMENT - a.typeInfo.arrayType.BYTES_PER_ELEMENT + ); + + const alignment = this.fields[0].typeInfo.arrayType.BYTES_PER_ELEMENT; + + this.elemSize = Math.ceil(this.elemSize / alignment) * alignment; + this.size = size; + + this.buffer = new ArrayBuffer(this.size * this.elemSize); + + this.fieldIndexes = {}; + let currentIdx = 0; + let currentOffset = 0; + for (let field of this.fields) { + this.fieldIndexes[field.name] = currentIdx++; + + field.typeElemSize = this.elemSize / field.typeInfo.arrayType.BYTES_PER_ELEMENT; + field.typeOffset = currentOffset / field.typeInfo.arrayType.BYTES_PER_ELEMENT; + field.typeArray = new field.typeInfo.arrayType(this.buffer); + + currentOffset += field.typeInfo.arrayType.BYTES_PER_ELEMENT; + } + } + + getSize() { + return this.size; + } + + setElement(idx, obj) { + const elemOffset = idx * this.elemSize; + + for (let field of this.fields) { + field.typeArray[idx * field.typeElemSize + field.typeOffset] = obj[field.name] || 0; + } + } + + setElementFieldValue(idx, fieldName, fieldValue) { + if (!(fieldName in this.fieldIndexes)) { + throw new Error('Unknown field: ' + fieldName); + } + + const field = this.fields[this.fieldIndexes[fieldName]]; + + field.typeArray[idx * field.typeElemSize + field.typeOffset] = fieldValue || 0; + } + + getElement(idx) { + const elemOffset = idx * this.elemSize; + + let obj = {}; + for (let field of this.fields) { + obj[field.name] = field.typeArray[idx * field.typeElemSize + field.typeOffset]; + } + + return obj; + } + + getElementFieldValue(idx, fieldName) { + if (!(fieldName in this.fieldIndexes)) { + throw new Error('Unknown field: ' + fieldName); + } + + const field = this.fields[this.fieldIndexes[fieldName]]; + + return field.typeArray[idx * field.typeElemSize + field.typeOffset]; + } +} diff --git a/assets/web-ui/js/widget.js b/assets/web-ui/js/widget.js new file mode 100644 index 0000000..2a42702 --- /dev/null +++ b/assets/web-ui/js/widget.js @@ -0,0 +1,1140 @@ +import * as utils from './utils.js'; +import * as fmt from './fmt.js'; +import * as math from './math.js'; +import * as svg from './svg.js'; + +function renderSVGTimeGrid(viewPort, timeRangeUs, detailed) { + const timeRangeNs = timeRangeUs.copy().scale(1000); + const delta = timeRangeNs.length(); + let step = Math.pow(10, parseInt(Math.log10(delta))); + if (delta / step < 4) { + step /= 5; + } + + step = Math.max(step, 1000); + + const minorStep = step / 5; + + let tickTime = (parseInt(timeRangeNs.begin / minorStep) + 1) * minorStep; + while (1) { + const majorTick = tickTime % step == 0; + const x = viewPort.width * (tickTime - timeRangeNs.begin) / delta; + viewPort.appendChild(svg.createNode('line', { + x1: x, + y1: 0, + x2: x, + y2: viewPort.height, + stroke: '#777', + 'stroke-width': majorTick ? 0.5 : 0.2 + })); + + if (majorTick) { + if (detailed) { + const units = ['s', 'ms', 'us', 'ns']; + let t = tickTime / 1000; + let line = 0; + while (t > 0) { + const unit = units.pop(); + const m = t % 1000; + t = parseInt(t / 1000); + if (m == 0) { + continue; + } + + viewPort.appendChild(svg.createNode('text', { + x: x + 2, + y: viewPort.height - 10 - 20 * line++, + width: 100, + height: 15, + 'font-size': 12, + fill: line > 1 ? '#777' : '#ccc', + }, node => { + node.textContent = m + unit; + })); + } + } else { + viewPort.appendChild(svg.createNode( + 'text', + { + x: x + 2, + y: viewPort.height - 10, + width: 100, + height: 15, + 'font-size': 12, + fill: '#aaa', + }, + node => node.textContent = fmt.time(tickTime / 1000) + )); + } + } + + tickTime += minorStep; + if (tickTime > timeRangeNs.end) { + break; + } + } +} + +function renderSVGMultiLineText(viewPort, lines) { + let y = 15; + + const text = svg.createNode('text', { + x: 0, + y: y, + 'font-size': 12, + fill: '#fff', + }); + + viewPort.appendChild(text); + + for (let line of lines) { + text.appendChild(svg.createNode( + 'tspan', + { + x: 0, + y: y, + }, + node => node.textContent = line + )); + + y += 15; + } +} + +function renderSVGMetricValuesPlot(viewPort, profileData, metric, timeRange) { + const timeComponentMetric = ['ct', 'it'].includes(metric); + const valueRange = timeComponentMetric ? new math.Range(0, 1) : profileData.getStats().getRange(metric); + + const step = 4; + let previousMetricValues = null; + let points = []; + console.time('renderSVGMetricValuesPlot') + for (let i = 0; i < viewPort.width; i += step) { + const currentMetricValues = profileData.getMetricValues( + timeRange.lerp(i / viewPort.width) + ); + + if (timeComponentMetric && previousMetricValues == null) { + previousMetricValues = currentMetricValues; + + continue; + } + + let currentValue = currentMetricValues.getValue(metric); + if (timeComponentMetric) { + currentValue = (currentMetricValues.getValue(metric) - previousMetricValues.getValue(metric)) + / (currentMetricValues.getValue('wt') - previousMetricValues.getValue('wt')) + ; + } + + points.push(i); + points.push(parseInt( + viewPort.height * ( + 1 - valueRange.lerpDist(currentValue) + ) + )); + + previousMetricValues = currentMetricValues; + } + + console.timeEnd('renderSVGMetricValuesPlot') + + viewPort.appendChild(svg.createNode('polyline', { + points: points.join(' '), + stroke: '#0af', + 'stroke-width': 2, + fill: 'none', + })); + + const tickValueStep = valueRange.lerp(0.25); + let tickValue = tickValueStep; + while (tickValue < valueRange.end) { + const y = parseInt(viewPort.height * (1 - valueRange.lerpDist(tickValue))); + + viewPort.appendChild(svg.createNode('line', { + x1: 0, + y1: y, + x2: viewPort.width, + y2: y, + stroke: '#777', + 'stroke-width': 0.5 + })); + + viewPort.appendChild(svg.createNode('text', { + x: 10, + y: y - 5, + width: 100, + height: 15, + 'font-size': 12, + fill: '#aaa', + }, node => { + const formatter = timeComponentMetric ? fmt.pct : profileData.getMetricFormatter(metric); + node.textContent = formatter(tickValue); + })); + + tickValue += tickValueStep; + } +} + +function getCallMetricValueColor(profileData, metric, value) { + const metricRange = profileData.getStats().getCallRange(metric); + + let scaleValue = 0; + + if (metricRange.length() > 100) { + scaleValue = + Math.log10(value - metricRange.begin) + / Math.log10(metricRange.length()) + ; + } else { + scaleValue = metricRange.lerp(value); + } + + return math.Vec3.lerpPath( + [ + new math.Vec3(0, 0.3, 0.9), + new math.Vec3(0, 0.9, 0.9), + new math.Vec3(0, 0.9, 0), + new math.Vec3(0.9, 0.9, 0), + new math.Vec3(0.9, 0.2, 0), + ], + scaleValue + ).toHTMLColor(); +} + + +class ViewTimeRange { + + constructor(timeRange, wallTime, viewWidth) { + this.setTimeRange(timeRange); + this.wallTime = wallTime; + this.setViewWidth(viewWidth); + } + + setTimeRange(timeRange) { + this.timeRange = timeRange.copy(); + } + + setViewWidth(viewWidth) { + this.viewWidth = viewWidth; + } + + fix() { + const minLength = 3; + this.timeRange.bound(0, this.wallTime); + if (this.timeRange.length() >= minLength) { + return this; + } + + this.timeRange.end = this.timeRange.begin + minLength; + if (this.timeRange.end > this.wallTime) { + this.timeRange.shift(this.wallTime - this.timeRange.end); + } + + return this; + } + + shiftViewRange(dist) { + this.timeRange = this._viewRangeToTimeRange( + this.getViewRange().shift(dist) + ); + + return this.fix(); + } + + shiftScaledViewRange(dist) { + return this.shiftViewRange(dist / this.getScale()); + } + + zoomScaledViewRange(factor, center) { + center /= this.getScale(); // scaled + center += this.getViewRange().begin; // translated + center /= this.viewWidth; // view space -> norm space + center *= this.wallTime; // norm space -> time space + + this.timeRange.shift(-center); + this.timeRange.scale(1 / factor); + this.timeRange.shift(center); + + return this.fix(); + } + + getScale() { + return this.wallTime / this.timeRange.length(); + } + + getViewRange() { + return this._timeRangeToViewRange(this.timeRange); + } + + getScaledViewRange() { + return this.getViewRange().scale(this.getScale()); + } + + getTimeRange() { + return this.timeRange.copy(); + } + + _viewRangeToTimeRange(range) { + return range.copy().scale(this.wallTime / this.viewWidth); + } + + _timeRangeToViewRange(range) { + return range.copy().scale(this.viewWidth / this.wallTime); + } +} + +class ViewPort { + + constructor(width, height, x, y) { + this.width = width; + this.height = height; + this.x = x || 0; + this.y = y || 0; + + this.node = svg.createNode('svg', { + width: this.width, + height: this.height, + x: this.x, + y: this.y, + }); + } + + createSubViewPort(width, height, x, y) { + const viewPort = new ViewPort(width, height, x, y); + this.appendChild(viewPort.node); + + return viewPort; + } + + resize(width, height) { + this.width = width; + this.height = height; + this.node.setAttribute('width', this.width); + this.node.setAttribute('height', this.height); + } + + appendChild(child) { + this.node.appendChild(child); + } + + clear() { + while (this.node.firstChild) { + this.node.removeChild(this.node.firstChild); + } + } +} + +class Widget { + + constructor(container, profileData) { + this.container = container; + this.profileData = profileData; + this.currentMetric = profileData.getMetadata().enabled_metrics[0]; + + $(window).on('resize', () => { + this._fitToContainerSize(); + }); + } + + setCurrentMetric(metric) { + this.currentMetric = metric; + } + + clear() { + this.container.empty(); + } + + render() { + } + + repaint() { + const id = this.container.attr('id'); + console.time('repaint ' + id); + this.clear(); + this.render(); + console.timeEnd('repaint ' + id); + } + + _fitToContainerSize() { + this.repaint(); + } +} + +class SVGWidget extends Widget { + + constructor(container, profileData) { + super(container, profileData); + + this.viewPort = new ViewPort( + this.container.width(), + this.container.height() + ); + + this.container.append(this.viewPort.node); + + setTimeout(() => this._fitToContainerSize(), 0); + } + + clear() { + this.viewPort.clear(); + } + + _fitToContainerSize() { + this.viewPort.resize(0, 0); + this.viewPort.resize( + this.container.width(), + this.container.height() + ); + + super._fitToContainerSize(); + } +} + +export class ColorScale extends SVGWidget { + + constructor(container, profileData) { + super(container, profileData); + } + + render() { + const step = 8; + const exp = 5; + + const getCurrentMetricValue = (x) => { + return this + .profileData + .getStats() + .getCallRange(this.currentMetric) + .lerp( + Math.pow(x, exp) / Math.pow(this.viewPort.width, exp) + ) + ; + } + + for (let i = 0; i < this.viewPort.width; i += step) { + this.viewPort.appendChild(svg.createNode('rect', { + x: i, + y: 0, + width: step, + height: this.viewPort.height, + fill: getCallMetricValueColor( + this.profileData, + this.currentMetric, + getCurrentMetricValue(i) + ), + })); + } + + for (let i = 0; i < this.viewPort.width; i += step * 20) { + this.viewPort.appendChild(svg.createNode('text', { + x: i, + y: this.viewPort.height - 5, + width: 100, + height: 15, + 'font-size': 12, + fill: '#777', + }, node => { + node.textContent = this.profileData.getMetricFormatter(this.currentMetric)( + getCurrentMetricValue(i) + ); + })); + } + } +} + +export class OverView extends SVGWidget { + + constructor(container, profileData) { + super(container, profileData); + + this.viewTimeRange = new ViewTimeRange( + this.profileData.getTimeRange(), + this.profileData.getWallTime(), + this.viewPort.width + ); + + const updateTimeRangeRect = () => { + if (!this.timeRangeRect) { + return; + } + + const viewRange = this.viewTimeRange.getViewRange(); + + this.timeRangeRect.setAttribute('x', viewRange.begin); + this.timeRangeRect.setAttribute('width', viewRange.length()); + } + + $(window).on('spx-timerange-change', (e, timeRange) => { + this.viewTimeRange.setTimeRange(timeRange); + updateTimeRangeRect(); + }); + + this.container.on('mousedown mousemove', e => { + if (e.type == 'mousemove' && e.buttons != 1) { + return; + } + + this.viewTimeRange.shiftViewRange( + e.clientX - this.viewTimeRange.getViewRange().center() + ); + + $(window).trigger('spx-timerange-change', [this.viewTimeRange.getTimeRange()]); + }); + } + + _fitToContainerSize() { + this.viewTimeRange.setViewWidth(this.container.width()); + super._fitToContainerSize(); + } + + render() { + this.viewPort.appendChild(svg.createNode('rect', { + x: 0, + y: 0, + width: this.viewPort.width, + height: this.viewPort.height, + 'fill-opacity': '0.3', + })); + + const calls = this.profileData.getCalls( + this.profileData.getTimeRange(), + 0.3 / this.viewPort.width + ); + + for (let i = 0; i < calls.length; i++) { + const call = calls[i]; + + const x = this.viewPort.width * call.getStart('wt') / this.profileData.getWallTime(); + const w = this.viewPort.width * call.getInc('wt') / this.profileData.getWallTime() - 1; + + if (w < 0.3) { + continue; + } + + const h = 1; + const y = call.getDepth(); + + this.viewPort.appendChild(svg.createNode('line', { + x1: x, + y1: y, + x2: x + w, + y2: y + h, + stroke: getCallMetricValueColor( + this.profileData, + this.currentMetric, + call.getInc(this.currentMetric) + ), + })); + } + + renderSVGTimeGrid( + this.viewPort, + this.profileData.getTimeRange() + ); + + if (this.currentMetric != 'wt') { + renderSVGMetricValuesPlot( + this.viewPort, + this.profileData, + this.currentMetric, + this.profileData.getTimeRange() + ); + } + + const viewRange = this.viewTimeRange.getViewRange(); + + this.timeRangeRect = svg.createNode('rect', { + x: viewRange.begin, + y: 0, + width: viewRange.length(), + height: this.viewPort.height, + stroke: new math.Vec3(0, 0.7, 0).toHTMLColor(), + 'stroke-width': 2, + fill: new math.Vec3(0, 1, 0).toHTMLColor(), + 'fill-opacity': '0.1', + }); + + this.viewPort.appendChild(this.timeRangeRect); + } +} + +export class TimeLine extends SVGWidget { + + constructor(container, profileData) { + super(container, profileData); + + this.viewTimeRange = new ViewTimeRange( + this.profileData.getTimeRange(), + this.profileData.getWallTime(), + this.viewPort.width + ); + + this.offsetY = 0; + + this.svgRectPool = new svg.NodePool('rect'); + this.svgTextPool = new svg.NodePool('text'); + + $(window).on('spx-timerange-change', (e, timeRange) => { + this.viewTimeRange.setTimeRange(timeRange.copy()); + this.repaint(); + }); + + this.container.bind('wheel', e => { + e.preventDefault(); + let f = 1.5; + if (e.originalEvent.deltaY < 0) { + f = 1 / f; + } + + this.viewTimeRange.zoomScaledViewRange(f, e.clientX); + + $(window).trigger('spx-timerange-change', [this.viewTimeRange.getTimeRange()]); + }); + + let lastPos = {x: 0, y: 0}; + + this.container.mousedown(e => { + lastPos.x = e.clientX; + lastPos.y = e.clientY; + }); + + this.container.mousemove(e => { + let delta = { + x: e.clientX - lastPos.x, + y: e.clientY - lastPos.y, + }; + + lastPos.x = e.clientX; + lastPos.y = e.clientY; + + switch (e.buttons) { + case 1: + this.viewTimeRange.shiftScaledViewRange(-delta.x); + + this.offsetY += delta.y; + this.offsetY = Math.min(0, this.offsetY); + + break; + + case 4: + let f = Math.pow(1.01, Math.abs(delta.y)); + if (delta.y < 0) { + f = 1 / f; + } + + this.viewTimeRange.zoomScaledViewRange(f, e.clientX); + + break; + + default: + return; + } + + $(window).trigger('spx-timerange-change', [this.viewTimeRange.getTimeRange()]); + }); + } + + _fitToContainerSize() { + this.viewTimeRange.setViewWidth(this.container.width()); + super._fitToContainerSize(); + } + + render() { + this.viewPort.appendChild(svg.createNode('rect', { + x: 0, + y: 0, + width: this.viewPort.width, + height: this.viewPort.height, + 'fill-opacity': '0.1', + })); + + const timeRange = this.viewTimeRange.getTimeRange(); + const calls = this.profileData.getCalls( + timeRange, + timeRange.length() / 50000 + ); + + const viewRange = this.viewTimeRange.getScaledViewRange(); + const offsetX = -viewRange.begin; + + this.svgRectPool.releaseAll(); + this.svgTextPool.releaseAll(); + + for (let i = 0; i < calls.length; i++) { + const call = calls[i]; + + let x = offsetX + this.viewPort.width * call.getStart('wt') / timeRange.length(); + if (x > this.viewPort.width) { + continue; + } + + let w = this.viewPort.width * call.getInc('wt') / timeRange.length() - 1; + if (w < 0.3 || x + w < 0) { + continue; + } + + w = x < 0 ? w + x : w; + x = x < 0 ? 0 : x; + w = Math.min(w, this.viewPort.width - x); + + const h = 12; + const y = (h + 1) * call.getDepth() + this.offsetY; + + const rect = this.svgRectPool.acquire({ + x: x, + y: y, + width: w, + height: h, + stroke: 'none', + 'stroke-width': 2, + fill: getCallMetricValueColor( + this.profileData, + this.currentMetric, + call.getInc(this.currentMetric) + ), + 'data-call-idx': call.getIdx(), + }); + + this.viewPort.appendChild(rect); + + if (w > 20) { + const text = this.svgTextPool.acquire({ + x: x + 2, + y: y + (h * 0.75), + width: w, + height: h, + 'font-size': h - 2, + }); + + text.textContent = utils.truncateFunctionName(call.getFunctionName(), w / 7); + this.viewPort.appendChild(text); + } + } + + const overlayHeight = 100; + const overlayViewPort = this.viewPort.createSubViewPort( + this.viewPort.width, + overlayHeight, + 0, + this.viewPort.height - overlayHeight + ); + + overlayViewPort.appendChild(svg.createNode('rect', { + x: 0, + y: 0, + width: overlayViewPort.width, + height: overlayViewPort.height, + 'fill-opacity': '0.5', + })); + + renderSVGTimeGrid( + this.viewPort, + timeRange, + true + ); + + if (this.currentMetric != 'wt') { + renderSVGMetricValuesPlot( + overlayViewPort, + this.profileData, + this.currentMetric, + timeRange + ); + } + + const infoViewPort = overlayViewPort.createSubViewPort( + overlayViewPort.width, + 65, + 0, + 0 + ); + + let pointedElement = null; + + this.viewPort.node.addEventListener('mouseout', (e) => { + if (pointedElement != null) { + pointedElement.setAttribute('stroke', 'none'); + pointedElement = null; + } + + infoViewPort.clear(); + }); + + this.viewPort.node.addEventListener('mousemove', (e) => { + if (pointedElement != null) { + pointedElement.setAttribute('stroke', 'none'); + pointedElement = null; + } + + infoViewPort.clear(); + + pointedElement = document.elementFromPoint(e.clientX, e.clientY); + if (pointedElement.nodeName == 'text') { + pointedElement = pointedElement.previousSibling; + } + + const callIdx = pointedElement.dataset.callIdx; + if (callIdx === undefined) { + pointedElement = null; + + return; + } + + pointedElement.setAttribute('stroke', '#0ff'); + + infoViewPort.appendChild(svg.createNode('rect', { + x: 0, + y: 0, + width: infoViewPort.width, + height: infoViewPort.height, + 'fill-opacity': '0.5', + })); + + const call = this.profileData.getCall(callIdx); + const currentMetricName = this.profileData.getMetricInfo(this.currentMetric).name; + const formatter = this.profileData.getMetricFormatter(this.currentMetric); + + renderSVGMultiLineText( + infoViewPort.createSubViewPort( + infoViewPort.width - 5, + infoViewPort.height, + 5, + 0 + ), + [ + 'Function: ' + call.getFunctionName(), + 'Depth: ' + call.getDepth(), + currentMetricName + ' inc.: ' + formatter(call.getInc(this.currentMetric)), + currentMetricName + ' exc.: ' + formatter(call.getExc(this.currentMetric)), + ] + ); + }); + } +} + +export class FlameGraph extends SVGWidget { + + constructor(container, profileData) { + super(container, profileData); + + this.timeRange = this.profileData.getTimeRange(); + this.svgRectPool = new svg.NodePool('rect'); + this.svgTextPool = new svg.NodePool('text'); + + $(window).on('spx-timerange-change', (e, timeRange) => { + this.timeRange = timeRange.copy(); + this.repaint(); + }); + } + + render() { + this.viewPort.appendChild(svg.createNode('rect', { + x: 0, + y: 0, + width: this.viewPort.width, + height: this.viewPort.height, + 'fill-opacity': '0.1', + })); + + if (this.profileData.isReleasableMetric(this.currentMetric)) { + this.viewPort.appendChild(svg.createNode('text', { + x: this.viewPort.width / 4, + y: this.viewPort.height / 2, + height: 20, + 'font-size': 14, + fill: '#089', + }, function(node) { + node.textContent = 'This visualization is not available for this metric.'; + })); + + return; + } + + this.svgRectPool.releaseAll(); + this.svgTextPool.releaseAll(); + + const renderedCgNodes = []; + + const renderNode = (node, minInc, maxCumInc, x, y) => { + x = x || 0; + y = y || this.viewPort.height; + + const w = this.viewPort.width + * (node.getInc().getValue(this.currentMetric) - minInc) + / (maxCumInc) + - 1 + ; + + if (w < 0.3) { + return x; + } + + const h = math.bound(y / (node.getDepth() + 1), 2, 12); + y -= h + 0.5; + + let childrenX = x; + for (let child of node.getChildren()) { + childrenX = renderNode(child, minInc, maxCumInc, childrenX, y); + } + + renderedCgNodes.push(node); + const nodeIdx = renderedCgNodes.length - 1; + + this.viewPort.appendChild(this.svgRectPool.acquire({ + x: x, + y: y, + width: w, + height: h, + stroke: 'none', + 'stroke-width': 2, + fill: math.Vec3.lerp( + new math.Vec3(1, 0, 0), + new math.Vec3(1, 1, 0), + 0.5 + * Math.min(1, node.getDepth() / 20) + + 0.5 + * (node.getInc().getValue(this.currentMetric) - minInc) + / (maxCumInc) + ).toHTMLColor(), + 'fill-opacity': '1', + 'data-cg-node-idx': nodeIdx, + })); + + if (w > 20 && h > 5) { + const text = this.svgTextPool.acquire({ + x: x + 2, + y: y + (h * 0.75), + width: w, + height: h, + 'font-size': h - 2, + }); + + text.textContent = utils.truncateFunctionName(node.getFunctionName(), w / 7); + this.viewPort.appendChild(text); + } + + return Math.max(x + w, childrenX); + }; + + const cgRoot = this + .profileData + .getCallGraphStats(this.timeRange) + .getRoot() + ; + + const minInc = cgRoot.getMinInc().getValue(this.currentMetric); + const maxCumInc = cgRoot.getMaxCumInc().getValue(this.currentMetric); + + let x = 0; + for (const child of cgRoot.getChildren()) { + x = renderNode(child, minInc, maxCumInc, x); + } + + const infoViewPort = this.viewPort.createSubViewPort( + this.viewPort.width, + 65, + 0, + 0 + ); + + let pointedElement = null; + + this.viewPort.node.addEventListener('mouseout', (e) => { + if (pointedElement != null) { + pointedElement.setAttribute('stroke', 'none'); + pointedElement = null; + } + + infoViewPort.clear(); + }); + + this.viewPort.node.addEventListener('mousemove', (e) => { + if (pointedElement != null) { + pointedElement.setAttribute('stroke', 'none'); + pointedElement = null; + } + + infoViewPort.clear(); + + pointedElement = document.elementFromPoint(e.clientX, e.clientY); + if (pointedElement.nodeName == 'text') { + pointedElement = pointedElement.previousSibling; + } + + const cgNodeIdx = pointedElement.dataset.cgNodeIdx; + if (cgNodeIdx === undefined) { + pointedElement = null; + + return; + } + + pointedElement.setAttribute('stroke', '#0ff'); + + infoViewPort.appendChild(svg.createNode('rect', { + x: 0, + y: 0, + width: infoViewPort.width, + height: infoViewPort.height, + 'fill-opacity': '0.5', + })); + + const cgNode = renderedCgNodes[cgNodeIdx]; + const currentMetricName = this.profileData.getMetricInfo(this.currentMetric).name; + const formatter = this.profileData.getMetricFormatter(this.currentMetric); + + renderSVGMultiLineText( + infoViewPort.createSubViewPort( + infoViewPort.width - 5, + infoViewPort.height, + 5, + 0 + ), + [ + 'Function: ' + cgNode.getFunctionName(), + 'Depth: ' + cgNode.getDepth(), + 'Called: ' + cgNode.getCalled(), + currentMetricName + ' inc.: ' + formatter(cgNode.getInc().getValue(this.currentMetric)), + ] + ); + }); + }; +} + +export class FlatProfile extends Widget { + + constructor(container, profileData) { + super(container, profileData); + + this.timeRange = this.profileData.getTimeRange(); + this.sortCol = 'exc'; + this.sortDir = -1; + + $(window).on('spx-timerange-change', (e, timeRange) => { + this.timeRange = timeRange.copy(); + this.repaint(); + }); + } + + render() { + + let html = ` + + + + + + + + + + + + + + + + + + +
FunctionCalledWall Time
PercentageValue
Inc.Exc.Inc.Exc.
+ `; + + html += ` +
+ + `; + + let functionsStats = this.profileData.getFunctionsStats(this.timeRange); + + functionsStats.sort((a, b) => { + switch (this.sortCol) { + case 'name': + a = a.functionName; + b = b.functionName; + + break; + + case 'called': + a = a.called; + b = b.called; + + break; + + case 'inc_rel': + case 'inc': + a = a.inc.getValue(this.currentMetric); + b = b.inc.getValue(this.currentMetric); + + break; + + case 'exc_rel': + case 'exc': + default: + a = a.exc.getValue(this.currentMetric); + b = b.exc.getValue(this.currentMetric); + } + + return (a < b ? -1 : (a > b)) * this.sortDir; + }); + + const formatter = this.profileData.getMetricFormatter(this.currentMetric); + const limit = Math.min(100, functionsStats.length); + + for (let i = 0; i < limit; i++) { + const stats = functionsStats[i]; + + const inc = formatter(stats.inc.getValue(this.currentMetric)); + const incRel = fmt.pct( + this.profileData.getStats().getRange(this.currentMetric).lerpDist( + stats.inc.getValue(this.currentMetric) + ) + ); + + const exc = formatter(stats.exc.getValue(this.currentMetric)); + const excRel = fmt.pct( + this.profileData.getStats().getRange(this.currentMetric).lerpDist( + stats.exc.getValue(this.currentMetric) + ) + ); + + let funcName = stats.functionName; + if (stats.maxCycleDepth > 0) { + funcName += '@' + stats.maxCycleDepth; + } + + html += ` + + + + + + + + + `; + } + + html += '
+ ${utils.truncateFunctionName(funcName, (this.container.width() - 5 * 90) / 8)} + ${fmt.quantity(stats.called)}${incRel}${excRel}${inc}${exc}
'; + + this.container.append(html); + + this.container.find('th[data-sort="' + this.sortCol + '"]').addClass('sort'); + + this.container.find('th').click(e => { + let sortCol = $(e.target).data('sort'); + if (!sortCol) { + return; + } + + if (this.sortCol == sortCol) { + this.sortDir *= -1; + } + + this.sortCol = sortCol; + this.repaint(); + }); + } +} diff --git a/assets/web-ui/report.html b/assets/web-ui/report.html new file mode 100644 index 0000000..fefdcc2 --- /dev/null +++ b/assets/web-ui/report.html @@ -0,0 +1,226 @@ + + + + + SPX Report + + + +
+
+

Initializing...

+

+
+
+
+
+
+ + + +
+
+ +
+ 		+
+
+ +
+
+ + + +
+
+ 		+
+
+ + + + + + + + + + + + diff --git a/config.m4 b/config.m4 index ad4a2c1..b809ff5 100644 --- a/config.m4 +++ b/config.m4 @@ -19,14 +19,20 @@ if test "$PHP_SPX" = "yes"; then for dir in /usr/local /usr do - if test -f "$dir/include/zlib/zlib.h" - then - SPX_ZLIB_DIR="$dir" - SPX_ZLIB_INCDIR="$dir/include/zlib" - elif test -f "$dir/include/zlib.h" + for incdir in $dir/include/zlib $dir/include + do + if test -f "$incdir/zlib.h" + then + SPX_ZLIB_DIR="$dir" + SPX_ZLIB_INCDIR="$incdir" + + break + fi + done + + if test "$SPX_ZLIB_INCDIR" != "" then - SPX_ZLIB_DIR="$dir" - SPX_ZLIB_INCDIR="$dir/include" + break fi done @@ -40,19 +46,22 @@ if test "$PHP_SPX" = "yes"; then fi PHP_NEW_EXTENSION(spx, - src/php_spx.c \ - src/spx_profiler.c \ - src/spx_reporter_fp.c \ - src/spx_reporter_trace.c \ - src/spx_reporter_cg.c \ - src/spx_reporter_gte.c \ - src/spx_metric.c \ - src/spx_resource_stats.c \ - src/spx_hset.c \ - src/spx_output_stream.c \ - src/spx_php.c \ - src/spx_stdio.c \ - src/spx_config.c \ + src/php_spx.c \ + src/spx_profiler.c \ + src/spx_reporter_full.c \ + src/spx_reporter_fp.c \ + src/spx_reporter_trace.c \ + src/spx_metric.c \ + src/spx_resource_stats.c \ + src/spx_hset.c \ + src/spx_str_builder.c \ + src/spx_output_stream.c \ + src/spx_php.c \ + src/spx_stdio.c \ + src/spx_config.c \ + src/spx_utils.c \ src/spx_fmt.c, $ext_shared) + + PHP_ADD_MAKEFILE_FRAGMENT fi diff --git a/src/php_spx.c b/src/php_spx.c index 6549e19..66d8102 100644 --- a/src/php_spx.c +++ b/src/php_spx.c @@ -1,58 +1,66 @@ #include -#include -#include -#include -#include #ifndef ZTS +# define USE_SIGNAL +#endif + +#ifdef USE_SIGNAL # include #endif -#include "main/SAPI.h" +#include "php_spx.h" #include "ext/standard/info.h" -#include "php_spx.h" #include "spx_thread.h" #include "spx_config.h" -#include "spx_stdio.h" #include "spx_php.h" #include "spx_utils.h" +#include "spx_metric.h" #include "spx_resource_stats.h" #include "spx_profiler.h" #include "spx_reporter_fp.h" -#include "spx_reporter_cg.h" -#include "spx_reporter_gte.h" +#include "spx_reporter_full.h" #include "spx_reporter_trace.h" -static SPX_THREAD_TLS struct { - struct { - volatile sig_atomic_t probing; - volatile sig_atomic_t stop; - volatile sig_atomic_t finish_called; - int signo; - } sig_handling; +typedef struct { + void (*init) (void); + void (*shutdown) (void); +} execution_handler_t; +static SPX_THREAD_TLS struct { int cli_sapi; + spx_config_t config; - struct { - int stdout_fd; - int stderr_fd; - } fd_backup; + execution_handler_t * execution_handler; - spx_config_t config; - spx_profiler_t * profiler; + struct { +#ifdef USE_SIGNAL + struct { + int handler_set; + struct { + struct sigaction sigint; + struct sigaction sigterm; + } prev_handler; + + volatile sig_atomic_t probing; + volatile sig_atomic_t stop; + volatile sig_atomic_t finish_called; + int signo; + } sig_handling; +#endif - char output_file[512]; + spx_profiler_t * profiler; + } profiling_handler; } context; -/* - * PHP way of managing global state: currently only used for INI entries. - */ ZEND_BEGIN_MODULE_GLOBALS(spx) + const char * data_dir; zend_bool http_enabled; const char * http_key; const char * http_ip_var; const char * http_ip_whitelist; + const char * http_ui_assets_dir; + const char * http_ui_uri_prefix; ZEND_END_MODULE_GLOBALS(spx) ZEND_DECLARE_MODULE_GLOBALS(spx) @@ -64,32 +72,74 @@ ZEND_DECLARE_MODULE_GLOBALS(spx) #endif PHP_INI_BEGIN() - STD_PHP_INI_ENTRY("spx.http_enabled", "0", PHP_INI_SYSTEM, OnUpdateBool, http_enabled, zend_spx_globals, spx_globals) - STD_PHP_INI_ENTRY("spx.http_key", "", PHP_INI_SYSTEM, OnUpdateString, http_key, zend_spx_globals, spx_globals) - STD_PHP_INI_ENTRY("spx.http_ip_var", "REMOTE_ADDR", PHP_INI_SYSTEM, OnUpdateString, http_ip_var, zend_spx_globals, spx_globals) - STD_PHP_INI_ENTRY("spx.http_ip_whitelist", "", PHP_INI_SYSTEM, OnUpdateString, http_ip_whitelist, zend_spx_globals, spx_globals) + STD_PHP_INI_ENTRY( + "spx.data_dir", "/tmp/spx", PHP_INI_SYSTEM, + OnUpdateString, data_dir, zend_spx_globals, spx_globals + ) + STD_PHP_INI_ENTRY( + "spx.http_enabled", "0", PHP_INI_SYSTEM, + OnUpdateBool, http_enabled, zend_spx_globals, spx_globals + ) + STD_PHP_INI_ENTRY( + "spx.http_key", "", PHP_INI_SYSTEM, + OnUpdateString, http_key, zend_spx_globals, spx_globals + ) + STD_PHP_INI_ENTRY( + "spx.http_ip_var", "REMOTE_ADDR", PHP_INI_SYSTEM, + OnUpdateString, http_ip_var, zend_spx_globals, spx_globals + ) + STD_PHP_INI_ENTRY( + "spx.http_ip_whitelist", "", PHP_INI_SYSTEM, + OnUpdateString, http_ip_whitelist, zend_spx_globals, spx_globals + ) + STD_PHP_INI_ENTRY( + "spx.http_ui_assets_dir", SPX_HTTP_UI_ASSETS_DIR, PHP_INI_SYSTEM, + OnUpdateString, http_ui_assets_dir, zend_spx_globals, spx_globals + ) + STD_PHP_INI_ENTRY( + "spx.http_ui_uri_prefix", "/_spx", PHP_INI_SYSTEM, + OnUpdateString, http_ui_uri_prefix, zend_spx_globals, spx_globals + ) PHP_INI_END() -PHP_MINIT_FUNCTION(spx); -PHP_MSHUTDOWN_FUNCTION(spx); -PHP_RINIT_FUNCTION(spx); -PHP_RSHUTDOWN_FUNCTION(spx); -PHP_MINFO_FUNCTION(spx); +static PHP_MINIT_FUNCTION(spx); +static PHP_MSHUTDOWN_FUNCTION(spx); +static PHP_RINIT_FUNCTION(spx); +static PHP_RSHUTDOWN_FUNCTION(spx); +static PHP_MINFO_FUNCTION(spx); -static void ex_hook_before(void); -static void ex_hook_after(void); -static void terminate(void); +static int check_access(void); -#ifndef ZTS -static void terminate_handler(int signo); -static void setup_terminate_handler(void); +static void profiling_handler_init(void); +static void profiling_handler_shutdown(void); +static void profiling_handler_ex_set_context(void); +static void profiling_handler_ex_unset_context(void); +static void profiling_handler_ex_hook_before(void); +static void profiling_handler_ex_hook_after(void); +#ifdef USE_SIGNAL +static void profiling_handler_sig_terminate(void); +static void profiling_handler_sig_handler(int signo); +static void profiling_handler_sig_set_handler(void); +static void profiling_handler_sig_unset_handler(void); #endif -static int check_access(void); -static void init(void); -static void finish(void); -static void read_file_content(const char * file, size_t (*reader) (const void * ptr, size_t len)); -static void generate_output_file_name(char * str, size_t max, spx_config_output_t output_type); +static void http_ui_handler_init(void); +static void http_ui_handler_shutdown(void); +static int http_ui_handler_data(const char * data_dir, const char *relative_path); +static void http_ui_handler_list_metadata_files_callback(const char * file_name, size_t count); +static int http_ui_handler_output_file(const char * file_name); + +static void read_stream_content(FILE * stream, size_t (*callback) (const void * ptr, size_t len)); + +static execution_handler_t profiling_handler = { + profiling_handler_init, + profiling_handler_shutdown +}; + +static execution_handler_t http_ui_handler = { + http_ui_handler_init, + http_ui_handler_shutdown +}; static zend_function_entry spx_functions[] = { /* empty */ @@ -117,7 +167,7 @@ zend_module_entry spx_module_entry = { ZEND_GET_MODULE(spx) #endif -PHP_MINIT_FUNCTION(spx) +static PHP_MINIT_FUNCTION(spx) { #ifdef ZTS spx_php_hooks_init(); @@ -128,7 +178,7 @@ PHP_MINIT_FUNCTION(spx) return SUCCESS; } -PHP_MSHUTDOWN_FUNCTION(spx) +static PHP_MSHUTDOWN_FUNCTION(spx) { #ifdef ZTS spx_php_hooks_shutdown(); @@ -139,91 +189,69 @@ PHP_MSHUTDOWN_FUNCTION(spx) return SUCCESS; } -PHP_RINIT_FUNCTION(spx) -{ - init(); - - return SUCCESS; -} - -PHP_RSHUTDOWN_FUNCTION(spx) +static PHP_RINIT_FUNCTION(spx) { - finish(); + context.execution_handler = NULL; + context.cli_sapi = spx_php_is_cli_sapi(); - return SUCCESS; -} - -PHP_MINFO_FUNCTION(spx) -{ - php_info_print_table_start(); - - php_info_print_table_row(2, "SPX Support", "enabled"); - php_info_print_table_row(2, "SPX Version", PHP_SPX_VERSION); - - php_info_print_table_end(); - - DISPLAY_INI_ENTRIES(); -} + if (context.cli_sapi) { + spx_config_get(&context.config, context.cli_sapi, SPX_CONFIG_SOURCE_ENV, -1); + } else { + spx_config_get( + &context.config, + context.cli_sapi, + SPX_CONFIG_SOURCE_HTTP_COOKIE, + SPX_CONFIG_SOURCE_HTTP_HEADER, + SPX_CONFIG_SOURCE_HTTP_QUERY_STRING, + -1 + ); + } -static void ex_hook_before(void) -{ - context.sig_handling.probing = 1; - spx_php_function_t function; - spx_php_current_function(&function); + if (!check_access()) { + return SUCCESS; + } - spx_profiler_call_start(context.profiler, &function); - context.sig_handling.probing = 0; - if (context.sig_handling.stop) { - terminate(); + if (!context.cli_sapi) { + const char * request_uri = spx_php_global_array_get("_SERVER", "REQUEST_URI"); + if ( + request_uri + && spx_utils_str_starts_with(request_uri, SPX_G(http_ui_uri_prefix)) + ) { + context.execution_handler = &http_ui_handler; + } } -} -static void ex_hook_after(void) -{ - context.sig_handling.probing = 1; - spx_profiler_call_end(context.profiler); - context.sig_handling.probing = 0; - if (context.sig_handling.stop) { - terminate(); + if (!context.execution_handler && context.config.enabled) { + context.execution_handler = &profiling_handler; } -} -static void terminate(void) -{ - finish(); + if (context.execution_handler) { + context.execution_handler->init(); + } - exit(context.sig_handling.signo < 0 ? EXIT_SUCCESS : 128 + context.sig_handling.signo); + return SUCCESS; } -#ifndef ZTS -static void terminate_handler(int signo) +static PHP_RSHUTDOWN_FUNCTION(spx) { - if (context.sig_handling.finish_called > 0) { - return; - } - - context.sig_handling.signo = signo; - - if (context.sig_handling.probing) { - context.sig_handling.stop = 1; - - return; + if (context.execution_handler) { + context.execution_handler->shutdown(); } - terminate(); + return SUCCESS; } -static void setup_terminate_handler(void) +static PHP_MINFO_FUNCTION(spx) { - struct sigaction act; + php_info_print_table_start(); - act.sa_handler = terminate_handler; - act.sa_flags = 0; + php_info_print_table_row(2, PHP_SPX_EXTNAME " Support", "enabled"); + php_info_print_table_row(2, PHP_SPX_EXTNAME " Version", PHP_SPX_VERSION); - sigaction(SIGINT, &act, NULL); - sigaction(SIGTERM, &act, NULL); + php_info_print_table_end(); + + DISPLAY_INI_ENTRIES(); } -#endif static int check_access(void) { @@ -282,315 +310,448 @@ static int check_access(void) return 0; } -static void init(void) +static void profiling_handler_init(void) { - context.sig_handling.probing = 0; - context.sig_handling.stop = 0; - context.sig_handling.finish_called = 0; - context.sig_handling.signo = -1; - - context.cli_sapi = 0 == strcmp(sapi_module.name, "cli"); - - context.fd_backup.stdout_fd = -1; - context.fd_backup.stderr_fd = -1; - - context.profiler = NULL; - context.output_file[0] = 0; - - if (context.cli_sapi) { - spx_config_read(&context.config, SPX_CONFIG_SOURCE_ENV, -1); - } else { - spx_config_read( - &context.config, - SPX_CONFIG_SOURCE_HTTP_HEADER, - SPX_CONFIG_SOURCE_HTTP_QUERY_STRING, - -1 - ); - } - - if (!context.config.enabled) { - return; - } - - if (!check_access()) { - return; - } - - if (context.config.output_file) { - strcpy(context.output_file, context.config.output_file); - } +#ifdef USE_SIGNAL + context.profiling_handler.sig_handling.handler_set = 0; + context.profiling_handler.sig_handling.probing = 0; + context.profiling_handler.sig_handling.stop = 0; + context.profiling_handler.sig_handling.finish_called = 0; + context.profiling_handler.sig_handling.signo = -1; +#endif - if (!context.output_file[0]) { - generate_output_file_name( - context.output_file, - sizeof(context.output_file), - context.config.output - ); - } + profiling_handler_ex_set_context(); - spx_output_stream_t * output = NULL; - int fp_live = 0; - if ( - context.cli_sapi && - context.config.output == SPX_CONFIG_OUTPUT_FLAT_PROFILE && - !context.config.output_file - ) { - fp_live = context.config.fp_live && isatty(STDOUT_FILENO); - if (fp_live) { - context.fd_backup.stdout_fd = spx_stdio_disable(STDOUT_FILENO); - context.fd_backup.stderr_fd = spx_stdio_disable(STDERR_FILENO); - output = spx_output_stream_dopen(context.fd_backup.stdout_fd, 0); - } else { - output = spx_output_stream_dopen(STDOUT_FILENO, 0); - } - } else { - int compressed = 0; - size_t name_len = strlen(context.output_file); - if (name_len > 3 && strcmp(context.output_file + name_len - 3, ".gz") == 0) { - compressed = 1; - } + context.profiling_handler.profiler = NULL; + spx_profiler_reporter_t * reporter = NULL; - output = spx_output_stream_open(context.output_file, compressed); - } + switch (context.config.report) { + default: + case SPX_CONFIG_REPORT_FULL: + reporter = spx_reporter_full_create(SPX_G(data_dir), context.config.full_res); - if (!output) { - return; - } + break; - spx_profiler_reporter_t * reporter = NULL; - switch (context.config.output) { - default: - case SPX_CONFIG_OUTPUT_FLAT_PROFILE: + case SPX_CONFIG_REPORT_FLAT_PROFILE: reporter = spx_reporter_fp_create( - output, context.config.fp_focus, context.config.fp_inc, context.config.fp_rel, context.config.fp_limit, - fp_live + context.config.fp_live ); break; - case SPX_CONFIG_OUTPUT_CALLGRIND: - reporter = spx_reporter_cg_create(output); - - break; - - case SPX_CONFIG_OUTPUT_GOOGLE_TRACE_EVENT: - reporter = spx_reporter_gte_create(output); - - break; - - case SPX_CONFIG_OUTPUT_TRACE: - reporter = spx_reporter_trace_create(output, context.config.trace_safe); + case SPX_CONFIG_REPORT_TRACE: + reporter = spx_reporter_trace_create(context.config.trace_file, context.config.trace_safe); break; } if (!reporter) { - return; + goto error; } - spx_resource_stats_init(); - - context.profiler = spx_profiler_create( + context.profiling_handler.profiler = spx_profiler_create( context.config.max_depth, context.config.enabled_metrics, reporter ); - if (!context.profiler) { - spx_resource_stats_shutdown(); + if (!context.profiling_handler.profiler) { + goto error; + } + + return; +error: + profiling_handler_ex_unset_context(); +} + +static void profiling_handler_shutdown(void) +{ + context.profiling_handler.sig_handling.finish_called++; + + if (context.profiling_handler.sig_handling.finish_called != 1) { return; } + if (!context.profiling_handler.profiler) { + return; + } + + spx_profiler_finalize(context.profiling_handler.profiler); + spx_profiler_destroy(context.profiling_handler.profiler); + context.profiling_handler.profiler = NULL; + + profiling_handler_ex_unset_context(); +} + +static void profiling_handler_ex_set_context(void) +{ #ifndef ZTS spx_php_hooks_init(); #endif - spx_php_context_init(); + spx_php_execution_init(); + spx_resource_stats_init(); - spx_php_execution_hook(ex_hook_before, ex_hook_after, 0); + spx_php_execution_hook(profiling_handler_ex_hook_before, profiling_handler_ex_hook_after, 0); if (context.config.builtins) { - spx_php_execution_hook(ex_hook_before, ex_hook_after, 1); + spx_php_execution_hook(profiling_handler_ex_hook_before, profiling_handler_ex_hook_after, 1); } +#ifdef USE_SIGNAL + if (context.cli_sapi) { + profiling_handler_sig_set_handler(); + } +#endif +} + +static void profiling_handler_ex_unset_context(void) +{ +#ifdef USE_SIGNAL if (context.cli_sapi) { + profiling_handler_sig_unset_handler(); + } +#endif + + spx_resource_stats_shutdown(); + spx_php_execution_shutdown(); + #ifndef ZTS - setup_terminate_handler(); + spx_php_hooks_shutdown(); #endif - } else { - spx_php_output_disable(); +} + +static void profiling_handler_ex_hook_before(void) +{ +#ifdef USE_SIGNAL + context.profiling_handler.sig_handling.probing = 1; +#endif + + spx_profiler_call_start(context.profiling_handler.profiler); + +#ifdef USE_SIGNAL + context.profiling_handler.sig_handling.probing = 0; + if (context.profiling_handler.sig_handling.stop) { + profiling_handler_sig_terminate(); } +#endif } -static void finish(void) +static void profiling_handler_ex_hook_after(void) { - context.sig_handling.finish_called++; +#ifdef USE_SIGNAL + context.profiling_handler.sig_handling.probing = 1; +#endif - if (context.sig_handling.finish_called != 1) { - return; + spx_profiler_call_end(context.profiling_handler.profiler); + +#ifdef USE_SIGNAL + context.profiling_handler.sig_handling.probing = 0; + if (context.profiling_handler.sig_handling.stop) { + profiling_handler_sig_terminate(); } +#endif +} + +#ifdef USE_SIGNAL +static void profiling_handler_sig_terminate(void) +{ + profiling_handler_shutdown(); + + exit( + context.profiling_handler.sig_handling.signo < 0 ? + EXIT_SUCCESS : 128 + context.profiling_handler.sig_handling.signo + ); +} - if (!context.profiler) { +static void profiling_handler_sig_handler(int signo) +{ + if (context.profiling_handler.sig_handling.finish_called > 0) { return; } - spx_profiler_finalize(context.profiler); - spx_profiler_destroy(context.profiler); - context.profiler = NULL; + context.profiling_handler.sig_handling.signo = signo; - if (context.fd_backup.stdout_fd != -1) { - spx_stdio_restore(STDOUT_FILENO, context.fd_backup.stdout_fd); + if (context.profiling_handler.sig_handling.probing) { + context.profiling_handler.sig_handling.stop = 1; + + return; } - if (context.fd_backup.stderr_fd != -1) { - spx_stdio_restore(STDERR_FILENO, context.fd_backup.stderr_fd); + profiling_handler_sig_terminate(); +} + +static void profiling_handler_sig_set_handler(void) +{ + struct sigaction act; + + act.sa_handler = profiling_handler_sig_handler; + act.sa_flags = 0; + + sigaction(SIGINT, &act, &context.profiling_handler.sig_handling.prev_handler.sigint); + sigaction(SIGTERM, &act, &context.profiling_handler.sig_handling.prev_handler.sigterm); + + context.profiling_handler.sig_handling.handler_set = 1; +} + +static void profiling_handler_sig_unset_handler(void) +{ + if (!context.profiling_handler.sig_handling.handler_set) { + return; } - spx_resource_stats_shutdown(); + sigaction(SIGINT, &context.profiling_handler.sig_handling.prev_handler.sigint, NULL); + sigaction(SIGTERM, &context.profiling_handler.sig_handling.prev_handler.sigterm, NULL); + + context.profiling_handler.sig_handling.handler_set = 0; +} +#endif /* defined(USE_SIGNAL) */ + +static void http_ui_handler_init(void) +{ +#ifndef ZTS + spx_php_hooks_init(); +#endif - spx_php_output_restore(); + spx_php_execution_init(); + spx_php_execution_disable(); + spx_php_execution_output_disable(); +} - spx_php_execution_hook(NULL, NULL, 0); - spx_php_execution_hook(NULL, NULL, 1); +static void http_ui_handler_shutdown(void) +{ + spx_php_execution_shutdown(); #ifndef ZTS spx_php_hooks_shutdown(); #endif - if ( - context.cli_sapi && - !context.config.output_file && - context.config.output != SPX_CONFIG_OUTPUT_FLAT_PROFILE - ) { - fprintf(stderr, "\nSPX output file: %s\n", context.output_file); + const char * request_uri = spx_php_global_array_get("_SERVER", "REQUEST_URI"); + if (!request_uri) { + goto error_404; } - if (context.cli_sapi) { - return; + const char * prefix_pos = strstr(request_uri, SPX_G(http_ui_uri_prefix)); + if (prefix_pos != request_uri) { + goto error_404; } - spx_php_output_direct_print("HTTP/1.1 200 OK\r\n"); + char relative_path[512]; + strncpy(relative_path, request_uri + strlen(SPX_G(http_ui_uri_prefix)), sizeof(relative_path)); - switch (context.config.output) { - default: - case SPX_CONFIG_OUTPUT_FLAT_PROFILE: - case SPX_CONFIG_OUTPUT_TRACE: - spx_php_output_direct_print("Content-Type: text/plain\r\n"); + char * query_string = strchr(relative_path, '?'); + if (query_string) { + *query_string = 0; + } - break; + if (0 == strcmp(relative_path, "/")) { + strncpy(relative_path, "/index.html", sizeof(relative_path)); + } - case SPX_CONFIG_OUTPUT_CALLGRIND: - spx_php_output_direct_print("Content-Type: application/octet-stream\r\n"); + if (0 == http_ui_handler_data(SPX_G(data_dir), relative_path)) { + goto finish; + } - break; + char local_file_name[512]; + snprintf( + local_file_name, + sizeof(local_file_name), + "%s%s", + SPX_G(http_ui_assets_dir), + relative_path + ); - case SPX_CONFIG_OUTPUT_GOOGLE_TRACE_EVENT: - spx_php_output_direct_print("Content-Type: application/json\r\n"); + if (0 == http_ui_handler_output_file(local_file_name)) { + goto finish; + } - break; +error_404: + /* FIXME: 404 status does not work (response status is still 200) */ + spx_php_output_direct_print("HTTP/1.1 404 Not Found\r\n"); + spx_php_output_direct_print("Content-Type: text/plain\r\n"); + spx_php_output_direct_print("\r\n"); + spx_php_output_direct_print("File not found.\n"); + +finish: + spx_php_ouput_finalize(); +} + +static int http_ui_handler_data(const char * data_dir, const char *relative_path) +{ + if (0 == strcmp(relative_path, "/data/metrics")) { + spx_php_output_direct_print("HTTP/1.1 200 OK\r\n"); + spx_php_output_direct_print("Content-Type: application/json\r\n"); + spx_php_output_direct_print("\r\n"); + spx_php_output_direct_print("{\"results\": [\n"); + + SPX_METRIC_FOREACH(i, { + if (i > 0) { + spx_php_output_direct_print(","); + } + + spx_php_output_direct_print("{"); + spx_php_output_direct_print("\"key\": \""); + spx_php_output_direct_print(spx_metrics_info[i].key); + spx_php_output_direct_print("\","); + + spx_php_output_direct_print("\"name\": \""); + spx_php_output_direct_print(spx_metrics_info[i].name); + spx_php_output_direct_print("\","); + + spx_php_output_direct_print("\"type\": \""); + switch (spx_metrics_info[i].type) { + case SPX_FMT_TIME: + spx_php_output_direct_print("time"); + break; + + case SPX_FMT_MEMORY: + spx_php_output_direct_print("memory"); + break; + + case SPX_FMT_QUANTITY: + spx_php_output_direct_print("quantity"); + break; + + default: + ; + } + + spx_php_output_direct_print("\","); + + spx_php_output_direct_printf("\"releasable\": %d", spx_metrics_info[i].releasable); + + spx_php_output_direct_print("}\n"); + }); + + spx_php_output_direct_print("]}\n"); + + return 0; } + if (0 == strcmp(relative_path, "/data/reports/metadata")) { + spx_php_output_direct_print("HTTP/1.1 200 OK\r\n"); + spx_php_output_direct_print("Content-Type: application/json\r\n"); + spx_php_output_direct_print("\r\n"); + spx_php_output_direct_print("{\"results\": [\n"); - if (context.config.output != SPX_CONFIG_OUTPUT_FLAT_PROFILE) { - spx_php_output_direct_print("Content-Encoding: gzip\r\n"); - - spx_php_output_direct_print("Content-Disposition: attachment; filename=\""); + spx_reporter_full_metadata_list_files( + data_dir, + http_ui_handler_list_metadata_files_callback + ); - const char * basename = strrchr(context.output_file, '/') + 1; - spx_php_output_direct_write(basename, strrchr(basename, '.') - basename); + spx_php_output_direct_print("]}\n"); - spx_php_output_direct_print("\"\r\n"); + return 0; } - spx_php_output_direct_print("\r\n"); + const char * get_report_metadata_uri = "/data/reports/metadata/"; + if (spx_utils_str_starts_with(relative_path, get_report_metadata_uri)) { + char file_name[512]; + spx_reporter_full_metadata_get_file_name( + data_dir, + relative_path + strlen(get_report_metadata_uri), + file_name, + sizeof(file_name) + ); + + return http_ui_handler_output_file(file_name); + } - read_file_content(context.output_file, spx_php_output_direct_write); + const char * get_report_uri = "/data/reports/get/"; + if (spx_utils_str_starts_with(relative_path, get_report_uri)) { + char file_name[512]; + spx_reporter_full_get_file_name( + data_dir, + relative_path + strlen(get_report_uri), + file_name, + sizeof(file_name) + ); - remove(context.output_file); + return http_ui_handler_output_file(file_name); + } - spx_php_ouput_finalize(); + return -1; } -static void read_file_content(const char * file, size_t (*reader) (const void * ptr, size_t len)) +static void http_ui_handler_list_metadata_files_callback(const char * file_name, size_t count) { - FILE * fp = fopen(file, "rb"); - if (!fp) { - return; + if (count > 0) { + spx_php_output_direct_print(","); } - char buf[512]; - while (1) { - size_t read = fread(buf, 1, sizeof(buf), fp); - reader(buf, read); - - if (read < sizeof(buf)) { - break; - } + FILE * fp = fopen(file_name, "r"); + if (!fp) { + return; } + read_stream_content(fp, spx_php_output_direct_write); fclose(fp); } -static void generate_output_file_name(char * str, size_t max, spx_config_output_t output_type) +static int http_ui_handler_output_file(const char * file_name) { - const char * prefix; - const char * extension; - int compressed; + FILE * fp = fopen(file_name, "rb"); + if (!fp) { + return -1; + } - switch (output_type) { - default: - case SPX_CONFIG_OUTPUT_FLAT_PROFILE: - prefix = "spx.flat_profile"; - extension = "txt"; - compressed = 0; + char suffix[32]; + int suffix_offset = strlen(file_name) - (sizeof(suffix) - 1); + strncpy( + suffix, + file_name + (suffix_offset < 0 ? 0 : suffix_offset), + sizeof(suffix) + ); - break; + suffix[sizeof(suffix) - 1] = 0; - case SPX_CONFIG_OUTPUT_CALLGRIND: - prefix = "callgrind.out"; - extension = "dat"; - compressed = 1; + const int compressed = spx_utils_str_ends_with(suffix, ".gz"); + if (compressed) { + *strrchr(suffix, '.') = 0; + } - break; + const char * content_type = "application/octet-stream"; + if (spx_utils_str_ends_with(suffix, ".html")) { + content_type = "text/html; charset=utf-8"; + } else if (spx_utils_str_ends_with(suffix, ".css")) { + content_type = "text/css"; + } else if (spx_utils_str_ends_with(suffix, ".js")) { + content_type = "application/javascript"; + } else if (spx_utils_str_ends_with(suffix, ".json")) { + content_type = "application/json"; + } - case SPX_CONFIG_OUTPUT_GOOGLE_TRACE_EVENT: - prefix = "spx.google_trace_event"; - extension = "json"; - compressed = 1; + spx_php_output_direct_print("HTTP/1.1 200 OK\r\n"); + spx_php_output_direct_printf("Content-Type: %s\r\n", content_type); + if (compressed) { + spx_php_output_direct_print("Content-Encoding: gzip\r\n"); + } - break; + fseek(fp, 0L, SEEK_END); + spx_php_output_direct_printf("Content-Length: %ld\r\n", ftell(fp)); + rewind(fp); - case SPX_CONFIG_OUTPUT_TRACE: - prefix = "spx.trace"; - extension = "txt"; - compressed = 1; - - break; - } + spx_php_output_direct_print("\r\n"); - time_t timer; - time(&timer); + read_stream_content(fp, spx_php_output_direct_write); + fclose(fp); - char date[64]; - strftime( - date, - sizeof(date), - "%Y-%m-%d_%H:%M:%S", - localtime(&timer) - ); + return 0; +} - snprintf( - str, - max, - "/tmp/%s.%s.%d.%s%s", - prefix, - date, - rand(), - extension, - compressed ? ".gz" : "" - ); +static void read_stream_content(FILE * stream, size_t (*callback) (const void * ptr, size_t len)) +{ + char buf[8 * 1024]; + while (1) { + size_t read = fread(buf, 1, sizeof(buf), stream); + callback(buf, read); + + if (read < sizeof(buf)) { + break; + } + } } diff --git a/src/php_spx.h b/src/php_spx.h index f29a5ec..6bfb371 100644 --- a/src/php_spx.h +++ b/src/php_spx.h @@ -3,7 +3,6 @@ #endif #include "main/php.h" -#include "Zend/zend_extensions.h" /* linux 2.6+ or OSX */ #if !defined(linux) && !(defined(__APPLE__) && defined(__MACH__)) @@ -14,7 +13,7 @@ # error "Only x86-64 architecture is supported" #endif -#if ZEND_EXTENSION_API_NO < 220131226 || ZEND_EXTENSION_API_NO > 320170718 +#if ZEND_MODULE_API_NO < 20131226 || ZEND_MODULE_API_NO > 20170718 # error "Only the following PHP versions are supported: 5.6 to 7.2" #endif @@ -22,7 +21,7 @@ # error "ZTS is not yet supported" #endif -#define PHP_SPX_VERSION "0.1.2" #define PHP_SPX_EXTNAME "SPX" +#define PHP_SPX_VERSION "0.2.0" extern zend_module_entry spx_module_entry; diff --git a/src/spx_config.c b/src/spx_config.c index 3f16cb2..ad7ca08 100644 --- a/src/spx_config.c +++ b/src/spx_config.c @@ -14,8 +14,9 @@ typedef struct { const char * depth_str; const char * metrics_str; - const char * output_str; - const char * output_file; + const char * report_str; + + const char * full_res_str; const char * fp_focus_str; const char * fp_inc_str; @@ -23,27 +24,29 @@ typedef struct { const char * fp_limit_str; const char * fp_live_str; + const char * trace_file; const char * trace_safe_str; } source_data_t; typedef const char * (*source_handler_t) (const char * parameter); -static void init_config(spx_config_t * config); -static void fix_config(spx_config_t * config); +static void init_config(spx_config_t * config, int cli); +static void fix_config(spx_config_t * config, int cli); static void source_data_get(source_data_t * source_data, source_handler_t handler); static void source_data_to_config(const source_data_t * source_data, spx_config_t * config); static const char * source_handler_env(const char * parameter); +static const char * source_handler_http_cookie(const char * parameter); static const char * source_handler_http_header(const char * parameter); static const char * source_handler_http_query_string(const char * parameter); -void spx_config_read(spx_config_t * config, ...) +void spx_config_get(spx_config_t * config, int cli, ...) { - init_config(config); + init_config(config, cli); source_data_t source_data; va_list ap; - va_start(ap, config); + va_start(ap, cli); while (1) { spx_config_source_t source = va_arg(ap, spx_config_source_t); @@ -53,6 +56,10 @@ void spx_config_read(spx_config_t * config, ...) source_handler = source_handler_env; break; + case SPX_CONFIG_SOURCE_HTTP_COOKIE: + source_handler = source_handler_http_cookie; + break; + case SPX_CONFIG_SOURCE_HTTP_HEADER: source_handler = source_handler_http_header; break; @@ -75,10 +82,10 @@ void spx_config_read(spx_config_t * config, ...) va_end(ap); - fix_config(config); + fix_config(config, cli); } -static void init_config(spx_config_t * config) +static void init_config(spx_config_t * config, int cli) { config->enabled = 0; config->key = NULL; @@ -93,8 +100,9 @@ static void init_config(spx_config_t * config) config->enabled_metrics[SPX_METRIC_WALL_TIME] = 1; config->enabled_metrics[SPX_METRIC_ZE_MEMORY] = 1; - config->output = SPX_CONFIG_OUTPUT_FLAT_PROFILE; - config->output_file = NULL; + config->report = cli ? SPX_CONFIG_REPORT_FLAT_PROFILE : SPX_CONFIG_REPORT_FULL; + + config->full_res = 0; config->fp_focus = SPX_METRIC_WALL_TIME; config->fp_inc = 0; @@ -102,12 +110,22 @@ static void init_config(spx_config_t * config) config->fp_limit = 10; config->fp_live = 0; + config->trace_file = NULL; config->trace_safe = 0; } -static void fix_config(spx_config_t * config) +static void fix_config(spx_config_t * config, int cli) { - if (config->output == SPX_CONFIG_OUTPUT_FLAT_PROFILE) { + if (!cli) { + config->report = SPX_CONFIG_REPORT_FULL; + } + + if (config->report == SPX_CONFIG_REPORT_FULL) { + config->enabled_metrics[SPX_METRIC_WALL_TIME] = 1; + config->enabled_metrics[SPX_METRIC_ZE_MEMORY] = 1; + } + + if (config->report == SPX_CONFIG_REPORT_FLAT_PROFILE) { config->enabled_metrics[config->fp_focus] = 1; } } @@ -119,13 +137,14 @@ static void source_data_get(source_data_t * source_data, source_handler_t handle source_data->builtins_str = handler("SPX_BUILTINS"); source_data->depth_str = handler("SPX_DEPTH"); source_data->metrics_str = handler("SPX_METRICS"); - source_data->output_str = handler("SPX_OUTPUT"); - source_data->output_file = handler("SPX_OUTPUT_FILE"); + source_data->report_str = handler("SPX_REPORT"); + source_data->full_res_str = handler("SPX_FULL_RES"); source_data->fp_focus_str = handler("SPX_FP_FOCUS"); source_data->fp_inc_str = handler("SPX_FP_INC"); source_data->fp_rel_str = handler("SPX_FP_REL"); source_data->fp_limit_str = handler("SPX_FP_LIMIT"); source_data->fp_live_str = handler("SPX_FP_LIVE"); + source_data->trace_file = handler("SPX_TRACE_FILE"); source_data->trace_safe_str = handler("SPX_TRACE_SAFE"); } @@ -153,31 +172,29 @@ static void source_data_to_config(const source_data_t * source_data, spx_config_ }); SPX_UTILS_TOKENIZE_STRING(source_data->metrics_str, ',', token, 32, { - spx_metric_t metric = spx_metric_get_by_short_name(token); + spx_metric_t metric = spx_metric_get_by_key(token); if (metric != SPX_METRIC_NONE) { config->enabled_metrics[metric] = 1; } }); } - if (source_data->output_str) { - if (0 == strcmp(source_data->output_str, "fp")) { - config->output = SPX_CONFIG_OUTPUT_FLAT_PROFILE; - } else if (0 == strcmp(source_data->output_str, "cg")) { - config->output = SPX_CONFIG_OUTPUT_CALLGRIND; - } else if (0 == strcmp(source_data->output_str, "gte")) { - config->output = SPX_CONFIG_OUTPUT_GOOGLE_TRACE_EVENT; - } else if (0 == strcmp(source_data->output_str, "trace")) { - config->output = SPX_CONFIG_OUTPUT_TRACE; + if (source_data->report_str) { + if (0 == strcmp(source_data->report_str, "full")) { + config->report = SPX_CONFIG_REPORT_FULL; + } else if (0 == strcmp(source_data->report_str, "fp")) { + config->report = SPX_CONFIG_REPORT_FLAT_PROFILE; + } else if (0 == strcmp(source_data->report_str, "trace")) { + config->report = SPX_CONFIG_REPORT_TRACE; } } - if (source_data->output_file) { - config->output_file = source_data->output_file; + if (source_data->full_res_str) { + config->full_res = atoi(source_data->full_res_str); } if (source_data->fp_focus_str) { - spx_metric_t focus = spx_metric_get_by_short_name(source_data->fp_focus_str); + spx_metric_t focus = spx_metric_get_by_key(source_data->fp_focus_str); if (focus != SPX_METRIC_NONE) { config->fp_focus = focus; } @@ -199,6 +216,10 @@ static void source_data_to_config(const source_data_t * source_data, spx_config_ config->fp_live = *source_data->fp_live_str == '1' ? 1 : 0; } + if (source_data->trace_file) { + config->trace_file = source_data->trace_file; + } + if (source_data->trace_safe_str) { config->trace_safe = *source_data->trace_safe_str == '1' ? 1 : 0; } @@ -209,6 +230,11 @@ static const char * source_handler_env(const char * parameter) return getenv(parameter); } +static const char * source_handler_http_cookie(const char * parameter) +{ + return spx_php_global_array_get("_COOKIE", parameter); +} + static const char * source_handler_http_header(const char * parameter) { char key[128] = "HTTP_"; diff --git a/src/spx_config.h b/src/spx_config.h index c646504..cdee54b 100644 --- a/src/spx_config.h +++ b/src/spx_config.h @@ -5,11 +5,10 @@ #include "spx_metric.h" typedef enum { - SPX_CONFIG_OUTPUT_FLAT_PROFILE, - SPX_CONFIG_OUTPUT_CALLGRIND, - SPX_CONFIG_OUTPUT_GOOGLE_TRACE_EVENT, - SPX_CONFIG_OUTPUT_TRACE, -} spx_config_output_t; + SPX_CONFIG_REPORT_FULL, + SPX_CONFIG_REPORT_FLAT_PROFILE, + SPX_CONFIG_REPORT_TRACE, +} spx_config_report_t; typedef struct { int enabled; @@ -19,8 +18,9 @@ typedef struct { size_t max_depth; int enabled_metrics[SPX_METRIC_COUNT]; - spx_config_output_t output; - const char * output_file; + spx_config_report_t report; + + size_t full_res; spx_metric_t fp_focus; int fp_inc; @@ -28,15 +28,17 @@ typedef struct { size_t fp_limit; int fp_live; + const char * trace_file; int trace_safe; } spx_config_t; typedef enum { SPX_CONFIG_SOURCE_ENV, + SPX_CONFIG_SOURCE_HTTP_COOKIE, SPX_CONFIG_SOURCE_HTTP_HEADER, SPX_CONFIG_SOURCE_HTTP_QUERY_STRING, } spx_config_source_t; -void spx_config_read(spx_config_t * config, ...); +void spx_config_get(spx_config_t * config, int cli, ...); #endif /* SPX_CONFIG_H_DEFINED */ diff --git a/src/spx_fmt.c b/src/spx_fmt.c index 7468676..df8494c 100644 --- a/src/spx_fmt.c +++ b/src/spx_fmt.c @@ -203,14 +203,17 @@ void spx_fmt_row_reset(spx_fmt_row_t * row) static void resolve_time_format(double * value, const char ** format) { - if (*value >= 1000 * 1000) { + if (*value >= 1000 * 1000 * 1000) { *format = "%7.2fs"; + *value /= 1000 * 1000 * 1000; + } else if (*value >= 1000 * 1000) { + *format = "%6.1fms"; *value /= 1000 * 1000; } else if (*value >= 1000) { - *format = "%6.1fms"; + *format = "%6.1fus"; *value /= 1000; } else { - *format = "%6.fus"; + *format = "%6.fns"; } } diff --git a/src/spx_hset.c b/src/spx_hset.c index 342358a..58503a3 100644 --- a/src/spx_hset.c +++ b/src/spx_hset.c @@ -127,6 +127,15 @@ spx_hset_t * spx_hset_create( return NULL; } +void spx_hset_reset(spx_hset_t * hset) +{ + size_t i; + for (i = 0; i < hset->size; i++) { + bucket_release_chain(&hset->buckets[i]); + bucket_init(&hset->buckets[i]); + } +} + void spx_hset_destroy(spx_hset_t * hset) { size_t i; diff --git a/src/spx_hset.h b/src/spx_hset.h index d501220..f2b50cb 100644 --- a/src/spx_hset.h +++ b/src/spx_hset.h @@ -13,6 +13,7 @@ spx_hset_t * spx_hset_create( spx_hset_cmp_func_t cmp ); +void spx_hset_reset(spx_hset_t * hset); void spx_hset_destroy(spx_hset_t * hset); spx_hset_entry_t * spx_hset_get_entry( diff --git a/src/spx_metric.c b/src/spx_metric.c index b2d6df7..c1ff1f0 100644 --- a/src/spx_metric.c +++ b/src/spx_metric.c @@ -8,7 +8,7 @@ #ifdef __GNUC__ # define ARRAY_INIT_INDEX(idx) [idx] = #else -# define ARRAY_INIT_INDEX(idx) +# error "Please open an issue" #endif const spx_metric_info_t spx_metrics_info[SPX_METRIC_COUNT] = { @@ -16,58 +16,68 @@ const spx_metric_info_t spx_metrics_info[SPX_METRIC_COUNT] = { "wt", "Wall Time", SPX_FMT_TIME, + 0, }, ARRAY_INIT_INDEX(SPX_METRIC_CPU_TIME) { "ct", "CPU Time", SPX_FMT_TIME, + 0, }, ARRAY_INIT_INDEX(SPX_METRIC_IDLE_TIME) { "it", "Idle Time", SPX_FMT_TIME, + 0, }, ARRAY_INIT_INDEX(SPX_METRIC_ZE_MEMORY) { "zm", "ZE memory", SPX_FMT_MEMORY, + 1, }, ARRAY_INIT_INDEX(SPX_METRIC_ZE_ROOT_BUFFER) { "zr", "ZE root buffer", SPX_FMT_QUANTITY, + 1, }, ARRAY_INIT_INDEX(SPX_METRIC_ZE_OBJECT_COUNT) { "zo", "ZE object count", SPX_FMT_QUANTITY, + 1, }, ARRAY_INIT_INDEX(SPX_METRIC_ZE_ERROR_COUNT) { "ze", "ZE error count", SPX_FMT_QUANTITY, + 0, }, ARRAY_INIT_INDEX(SPX_METRIC_IO_BYTES) { "io", "I/O Bytes", SPX_FMT_MEMORY, + 0, }, ARRAY_INIT_INDEX(SPX_METRIC_IO_RBYTES) { "ior", "I/O Read Bytes", SPX_FMT_MEMORY, + 0, }, ARRAY_INIT_INDEX(SPX_METRIC_IO_WBYTES) { "iow", "I/O Written Bytes", SPX_FMT_MEMORY, + 0, }, }; -spx_metric_t spx_metric_get_by_short_name(const char * short_name) +spx_metric_t spx_metric_get_by_key(const char * key) { SPX_METRIC_FOREACH(i, { - if (0 == strcmp(spx_metrics_info[i].short_name, short_name)) { + if (0 == strcmp(spx_metrics_info[i].key, key)) { return i; } }); @@ -79,6 +89,7 @@ struct spx_metric_collector_t { int enabled_metrics[SPX_METRIC_COUNT]; double ref_values[SPX_METRIC_COUNT]; double last_values[SPX_METRIC_COUNT]; + double current_fixed_noise[SPX_METRIC_COUNT]; }; static void collect_raw_values(const int * enabled_metrics, double * current_values); @@ -95,6 +106,7 @@ spx_metric_collector_t * spx_metric_collector_create(const int * enabled_metrics SPX_METRIC_FOREACH(i, { collector->enabled_metrics[i] = enabled_metrics[i]; collector->ref_values[i] = collector->last_values[i]; + collector->current_fixed_noise[i] = 0; }); return collector; @@ -107,9 +119,40 @@ void spx_metric_collector_destroy(spx_metric_collector_t * collector) void spx_metric_collector_collect(spx_metric_collector_t * collector, double * values) { - collect_raw_values(collector->enabled_metrics, collector->last_values); + double current_values[SPX_METRIC_COUNT]; + collect_raw_values(collector->enabled_metrics, current_values); + + /* + * This branch is required to fix cpu / wall time inconsistency (cpu > wall time within a single thread). + */ + if ( + collector->enabled_metrics[SPX_METRIC_WALL_TIME] && + collector->enabled_metrics[SPX_METRIC_CPU_TIME] + ) { + const double ct_surplus = + (current_values[SPX_METRIC_CPU_TIME] - collector->last_values[SPX_METRIC_CPU_TIME]) + - (current_values[SPX_METRIC_WALL_TIME] - collector->last_values[SPX_METRIC_WALL_TIME]) + ; + + if (ct_surplus > 0) { + collector->ref_values[SPX_METRIC_CPU_TIME] += ct_surplus; + collector->ref_values[SPX_METRIC_IDLE_TIME] -= ct_surplus; + } + } SPX_METRIC_FOREACH(i, { + /* FIXME this branch should concern all non releasable metrics */ + if (i == SPX_METRIC_WALL_TIME || i == SPX_METRIC_CPU_TIME) { + const double diff = current_values[i] - collector->last_values[i]; + if (collector->current_fixed_noise[i] > diff) { + collector->current_fixed_noise[i] = diff; + } + } + + collector->ref_values[i] += collector->current_fixed_noise[i]; + collector->current_fixed_noise[i] = 0; + + collector->last_values[i] = current_values[i]; values[i] = collector->last_values[i] - collector->ref_values[i]; }); } @@ -120,7 +163,14 @@ void spx_metric_collector_noise_barrier(spx_metric_collector_t * collector) collect_raw_values(collector->enabled_metrics, current_values); SPX_METRIC_FOREACH(i, { - collector->ref_values[i] += current_values[i] - collector->last_values[i]; + collector->current_fixed_noise[i] += current_values[i] - collector->last_values[i]; + }); +} + +void spx_metric_collector_add_fixed_noise(spx_metric_collector_t * collector, const double * noise) +{ + SPX_METRIC_FOREACH(i, { + collector->current_fixed_noise[i] += noise[i]; }); } diff --git a/src/spx_metric.h b/src/spx_metric.h index 6e64f0a..5c8e183 100644 --- a/src/spx_metric.h +++ b/src/spx_metric.h @@ -30,14 +30,15 @@ do { \ } while (0) typedef struct { - const char * short_name; + const char * key; const char * name; spx_fmt_value_type_t type; + int releasable; } spx_metric_info_t; extern const spx_metric_info_t spx_metrics_info[SPX_METRIC_COUNT]; -spx_metric_t spx_metric_get_by_short_name(const char * short_name); +spx_metric_t spx_metric_get_by_key(const char * key); typedef struct spx_metric_collector_t spx_metric_collector_t; @@ -46,5 +47,6 @@ void spx_metric_collector_destroy(spx_metric_collector_t * collector); void spx_metric_collector_collect(spx_metric_collector_t * collector, double * values); void spx_metric_collector_noise_barrier(spx_metric_collector_t * collector); +void spx_metric_collector_add_fixed_noise(spx_metric_collector_t * collector, const double * noise); #endif /* SPX_METRIC_H_DEFINED */ diff --git a/src/spx_php.c b/src/spx_php.c index f9f83be..6cf0f6a 100644 --- a/src/spx_php.c +++ b/src/spx_php.c @@ -1,11 +1,15 @@ +#define _GNU_SOURCE /* vasprintf */ +#include +#undef _GNU_SOURCE /* to avoid clash in main/php_config.h */ + #include "main/php.h" #include "main/SAPI.h" -#include "Zend/zend_extensions.h" #include "spx_php.h" #include "spx_thread.h" +#include "spx_str_builder.h" -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 typedef size_t zend_write_len_t; #else typedef uint zend_write_len_t; @@ -20,7 +24,7 @@ static struct { void (*execute_ex) (zend_execute_data * execute_data TSRMLS_DC); void (*execute_internal) ( zend_execute_data * execute_data, -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 zval * return_value #else struct _zend_fcall_info * fci, @@ -50,12 +54,14 @@ static SPX_THREAD_TLS struct { } user, internal; } ex_hook; + int execution_disabled; + size_t error_count; int output_disabled; struct { void (*handler) (INTERNAL_FUNCTION_PARAMETERS); -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 zend_internal_arg_info * arg_info; uint32_t num_args; uint32_t fn_flags; @@ -73,7 +79,7 @@ static void hook_flush(void * server_context); static void hook_execute_ex(zend_execute_data * execute_data TSRMLS_DC); static void hook_execute_internal( zend_execute_data * execute_data, -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 zval * return_value #else struct _zend_fcall_info * fci, @@ -92,6 +98,12 @@ static void hook_zend_error_cb( static PHP_FUNCTION(null_zend_function); static zend_internal_function * get_zend_internal_function(const char * name); +static HashTable * get_global_array(const char * name); + +int spx_php_is_cli_sapi(void) +{ + return 0 == strcmp(sapi_module.name, "cli"); +} void spx_php_current_function(spx_php_function_t * function) { @@ -103,7 +115,7 @@ void spx_php_current_function(spx_php_function_t * function) function->class_name = get_active_class_name(&function->call_type TSRMLS_CC); function->func_name = get_active_function_name(TSRMLS_C); -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 const zend_function * func = EG(current_execute_data)->func; /* * Required for PHP 7+ to avoid function name default'd to "main" in this case @@ -123,6 +135,8 @@ void spx_php_current_function(spx_php_function_t * function) #endif if (!function->func_name) { + function->class_name = ""; + function->call_type = ""; function->func_name = function->file_name; } @@ -132,19 +146,16 @@ void spx_php_current_function(spx_php_function_t * function) ; } -const char * spx_php_global_array_get(const char * global_array_name, const char * key) +const char * spx_php_global_array_get(const char * name, const char * key) { -#if ZEND_EXTENSION_API_NO >= 320151012 - zend_string * global_array_name_zs = zend_string_init(global_array_name, strlen(global_array_name), 0); - - zend_is_auto_global(global_array_name_zs); - zval * global_array = zend_hash_find(&EG(symbol_table), global_array_name_zs); + HashTable * global_array = get_global_array(name); if (!global_array) { return NULL; } +#if ZEND_MODULE_API_NO >= 20151012 zval * pv = zend_hash_str_find( - Z_ARRVAL_P(global_array), + global_array, key, strlen(key) ); @@ -157,24 +168,10 @@ const char * spx_php_global_array_get(const char * global_array_name, const char return Z_STRVAL_P(pv); #else - TSRMLS_FETCH(); - - zend_is_auto_global(global_array_name, strlen(global_array_name) TSRMLS_CC); - - zval ** global_array; - if (zend_hash_find( - &EG(symbol_table), - global_array_name, - strlen(global_array_name) + 1, - (void **) &global_array - ) != SUCCESS) { - return NULL; - } - zval ** ppv; if ( zend_hash_find( - Z_ARRVAL_PP(global_array), + global_array, key, strlen(key) + 1, (void **) &ppv @@ -187,6 +184,105 @@ const char * spx_php_global_array_get(const char * global_array_name, const char #endif } +char * spx_php_build_command_line(void) +{ + HashTable * global_array = get_global_array("_SERVER"); + if (!global_array) { + return NULL; + } + + const char * argv_key = "argv"; + +#if ZEND_MODULE_API_NO >= 20151012 + zval * argv = zend_hash_str_find( + global_array, + argv_key, + strlen(argv_key) + ); + + if (!argv) { + goto error; + } + + if (Z_TYPE_P(argv) != IS_ARRAY) { + goto error; + } + + spx_str_builder_t * str_builder = spx_str_builder_create(1024); + if (!str_builder) { + goto error; + } + + HashTable * argv_array = Z_ARRVAL_P(argv); + zval * entry; + int i = 0; + + zend_hash_internal_pointer_reset(argv_array); + while ((entry = zend_hash_get_current_data(argv_array)) != NULL) { + if (Z_TYPE_PP(entry) == IS_STRING) { + if (i++ > 0) { + spx_str_builder_append_char(str_builder, ' '); + } + + if (0 == spx_str_builder_append_str(str_builder, Z_STRVAL_PP(entry))) { + break; + } + } + + zend_hash_move_forward(argv_array); + } +#else + zval ** argv; + if ( + zend_hash_find( + global_array, + argv_key, + strlen(argv_key) + 1, + (void **) &argv + ) != SUCCESS + ) { + goto error; + } + + if (Z_TYPE_PP(argv) != IS_ARRAY) { + goto error; + } + + spx_str_builder_t * str_builder = spx_str_builder_create(1024); + if (!str_builder) { + goto error; + } + + HashTable * argv_array = Z_ARRVAL_PP(argv); + HashPosition pos; + zval ** entry; + int i = 0; + + zend_hash_internal_pointer_reset_ex(argv_array, &pos); + while (zend_hash_get_current_data_ex(argv_array, (void **)&entry, &pos) == SUCCESS) { + if (Z_TYPE_PP(entry) == IS_STRING) { + if (i++ > 0) { + spx_str_builder_append_char(str_builder, ' '); + } + + if (0 == spx_str_builder_append_str(str_builder, Z_STRVAL_PP(entry))) { + break; + } + } + + zend_hash_move_forward_ex(argv_array, &pos); + } +#endif + + char * command_line = strdup(spx_str_builder_str(str_builder)); + spx_str_builder_destroy(str_builder); + + return command_line; + +error: + return strdup("n/a"); +} + size_t spx_php_zend_memory_usage(void) { TSRMLS_FETCH(); @@ -216,7 +312,7 @@ size_t spx_php_zend_object_count(void) size_t i, count = 0; for (i = 1; i < EG(objects_store).top; i++) { if ( -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 IS_OBJ_VALID(EG(objects_store).object_buckets[i]) #else EG(objects_store).object_buckets[i].valid @@ -302,17 +398,29 @@ void spx_php_hooks_shutdown(void) } } -void spx_php_context_init(void) +void spx_php_execution_init(void) { context.ex_hook.user.before = NULL; context.ex_hook.user.after = NULL; context.ex_hook.internal.before = NULL; context.ex_hook.internal.after = NULL; + context.execution_disabled = 0; context.error_count = 0; context.output_disabled = 0; } +void spx_php_execution_shutdown(void) +{ + spx_php_execution_output_restore(); + spx_php_execution_init(); +} + +void spx_php_execution_disable(void) +{ + context.execution_disabled = 1; +} + void spx_php_execution_hook(void (*before)(void), void (*after)(void), int internal) { if (internal) { @@ -324,7 +432,7 @@ void spx_php_execution_hook(void (*before)(void), void (*after)(void), int inter } } -void spx_php_output_disable(void) +void spx_php_execution_output_disable(void) { if (context.output_disabled == 1) { return; @@ -343,21 +451,21 @@ void spx_php_output_disable(void) if (func) { context.fastcgi_finish_request.handler = func->handler; context.fastcgi_finish_request.arg_info = func->arg_info; -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 context.fastcgi_finish_request.num_args = func->num_args; context.fastcgi_finish_request.fn_flags = func->fn_flags; #endif func->handler = PHP_FN(null_zend_function); func->arg_info = NULL; -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 func->num_args = 0; func->fn_flags &= ~(ZEND_ACC_VARIADIC | ZEND_ACC_HAS_TYPE_HINTS); #endif } } -void spx_php_output_restore(void) +void spx_php_execution_output_restore(void) { if (context.output_disabled == 0) { return; @@ -369,7 +477,7 @@ void spx_php_output_restore(void) if (func && context.fastcgi_finish_request.handler) { func->handler = context.fastcgi_finish_request.handler; func->arg_info = context.fastcgi_finish_request.arg_info; -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 func->num_args = context.fastcgi_finish_request.num_args; func->fn_flags = context.fastcgi_finish_request.fn_flags; #endif @@ -391,6 +499,25 @@ size_t spx_php_output_direct_print(const char * str) return spx_php_output_direct_write(str, strlen(str)); } +int spx_php_output_direct_printf(const char * fmt, ...) +{ + va_list ap; + va_start(ap, fmt); + + char * buf; + int printed = vasprintf(&buf, fmt, ap); + va_end(ap); + + if (printed < 0) { + return printed; + } + + printed = spx_php_output_direct_print(buf); + free(buf); + + return printed; +} + void spx_php_ouput_finalize(void) { TSRMLS_FETCH(); @@ -441,6 +568,10 @@ static void hook_flush(void * server_context) static void hook_execute_ex(zend_execute_data * execute_data TSRMLS_DC) { + if (context.execution_disabled) { + return; + } + if (context.ex_hook.user.before) { context.ex_hook.user.before(); } @@ -454,7 +585,7 @@ static void hook_execute_ex(zend_execute_data * execute_data TSRMLS_DC) static void hook_execute_internal( zend_execute_data * execute_data, -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 zval * return_value #else struct _zend_fcall_info * fci, @@ -468,7 +599,7 @@ static void hook_execute_internal( ze_hook.execute_internal( execute_data, -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 return_value #else fci, @@ -500,7 +631,7 @@ static PHP_FUNCTION(null_zend_function) static zend_internal_function * get_zend_internal_function(const char * name) { -#if ZEND_EXTENSION_API_NO >= 320151012 +#if ZEND_MODULE_API_NO >= 20151012 return zend_hash_str_find_ptr( CG(function_table), name, @@ -524,3 +655,43 @@ static zend_internal_function * get_zend_internal_function(const char * name) return NULL; #endif } + +static HashTable * get_global_array(const char * name) +{ +#if ZEND_MODULE_API_NO >= 20151012 + zend_string * name_zs = zend_string_init(name, strlen(name), 0); + + zend_is_auto_global(name_zs); + + zval * zv_array = zend_hash_find(&EG(symbol_table), name_zs); + if (!zv_array) { + return NULL; + } + + if (Z_TYPE_P(zv_array) != IS_ARRAY) { + return NULL; + } + + return Z_ARRVAL_P(zv_array); +#else + TSRMLS_FETCH(); + + zend_is_auto_global(name, strlen(name) TSRMLS_CC); + + zval ** zv_array; + if (zend_hash_find( + &EG(symbol_table), + name, + strlen(name) + 1, + (void **) &zv_array + ) != SUCCESS) { + return NULL; + } + + if (Z_TYPE_PP(zv_array) != IS_ARRAY) { + return NULL; + } + + return Z_ARRVAL_PP(zv_array); +#endif +} diff --git a/src/spx_php.h b/src/spx_php.h index 74d8379..6b0edae 100644 --- a/src/spx_php.h +++ b/src/spx_php.h @@ -12,9 +12,12 @@ typedef struct { const char * class_name; } spx_php_function_t; +int spx_php_is_cli_sapi(void); + void spx_php_current_function(spx_php_function_t * function); -const char * spx_php_global_array_get(const char * global_array_name, const char * key); +const char * spx_php_global_array_get(const char * name, const char * key); +char * spx_php_build_command_line(void); size_t spx_php_zend_memory_usage(void); size_t spx_php_zend_root_buffer_length(void); @@ -24,14 +27,17 @@ size_t spx_php_zend_error_count(void); void spx_php_hooks_init(void); void spx_php_hooks_shutdown(void); -void spx_php_context_init(void); +void spx_php_execution_init(void); +void spx_php_execution_shutdown(void); +void spx_php_execution_disable(void); void spx_php_execution_hook(void (*before)(void), void (*after)(void), int internal); -void spx_php_output_disable(void); -void spx_php_output_restore(void); +void spx_php_execution_output_disable(void); +void spx_php_execution_output_restore(void); size_t spx_php_output_direct_write(const void * ptr, size_t len); size_t spx_php_output_direct_print(const char * str); +int spx_php_output_direct_printf(const char * fmt, ...); void spx_php_ouput_finalize(void); diff --git a/src/spx_profiler.c b/src/spx_profiler.c index 86cb135..9db19e6 100644 --- a/src/spx_profiler.c +++ b/src/spx_profiler.c @@ -5,6 +5,7 @@ #include "spx_hset.h" #include "spx_fmt.h" #include "spx_profiler.h" +#include "spx_resource_stats.h" #define STACK_CAPACITY 2048 #define FUNC_TABLE_CAPACITY 65536 @@ -53,11 +54,6 @@ typedef struct { spx_profiler_metric_values_t children_metric_values; } stack_frame_t; -typedef struct { - size_t depth; - stack_frame_t frames[STACK_CAPACITY]; -} spx_stack_t; - struct spx_profiler_t { int finalized; int active; @@ -65,6 +61,10 @@ struct spx_profiler_t { int enabled_metrics[SPX_METRIC_COUNT]; spx_metric_collector_t * metric_collector; + int calibrated; + spx_profiler_metric_values_t call_start_noise; + spx_profiler_metric_values_t call_end_noise; + spx_profiler_reporter_t * reporter; size_t max_depth; @@ -75,10 +75,21 @@ struct spx_profiler_t { spx_profiler_metric_values_t cum_metric_values; spx_profiler_metric_values_t max_metric_values; - spx_stack_t stack; + struct { + size_t depth; + stack_frame_t frames[STACK_CAPACITY]; + } stack; + func_table_t func_table; }; +static spx_profiler_reporter_cost_t null_reporter_notify( + spx_profiler_reporter_t * reporter, + const spx_profiler_event_t * event +); + +static void calibrate(spx_profiler_t * profiler); + static unsigned long func_table_entry_hash(const void * v); static int func_table_entry_cmp(const void * va, const void * vb); @@ -88,18 +99,17 @@ static spx_profiler_func_table_entry_t * func_table_get_entry( ); static void fill_event( + spx_profiler_event_t * event, const spx_profiler_t * profiler, spx_profiler_event_type_t type, - const spx_php_function_t * caller, - const spx_php_function_t * callee, + const spx_profiler_func_table_entry_t * caller, + const spx_profiler_func_table_entry_t * callee, const spx_profiler_metric_values_t * inc, - const spx_profiler_metric_values_t * exc, - spx_profiler_event_t * event + const spx_profiler_metric_values_t * exc ); spx_profiler_reporter_t * spx_profiler_reporter_create( size_t size, - spx_output_stream_t * output, spx_profiler_reporter_notify_func_t notify, spx_profiler_reporter_destroy_func_t destroy ) { @@ -110,12 +120,9 @@ spx_profiler_reporter_t * spx_profiler_reporter_create( spx_profiler_reporter_t * reporter = malloc(size); if (!reporter) { - spx_output_stream_close(reporter->output); - return NULL; } - reporter->output = output; reporter->notify = notify; reporter->destroy = destroy; @@ -128,7 +135,6 @@ void spx_profiler_reporter_destroy(spx_profiler_reporter_t * reporter) reporter->destroy(reporter); } - spx_output_stream_close(reporter->output); free(reporter); } @@ -153,7 +159,11 @@ spx_profiler_t * spx_profiler_create( profiler->metric_collector = NULL; - profiler->max_depth = max_depth; + profiler->calibrated = 0; + METRIC_VALUES_ZERO(profiler->call_start_noise); + METRIC_VALUES_ZERO(profiler->call_end_noise); + + profiler->max_depth = max_depth > 0 && max_depth < STACK_CAPACITY ? max_depth : STACK_CAPACITY; profiler->called = 0; profiler->stack.depth = 0; @@ -215,14 +225,25 @@ void spx_profiler_destroy(spx_profiler_t * profiler) free(profiler); } -void spx_profiler_call_start( - spx_profiler_t * profiler, - const spx_php_function_t * function -) { +void spx_profiler_call_start(spx_profiler_t * profiler) +{ if (profiler->finalized) { return; } + profiler->active = profiler->stack.depth < profiler->max_depth; + if (!profiler->active) { + if (profiler->stack.depth == STACK_CAPACITY) { + fprintf(stderr, "SPX: STACK_CAPACITY (%d) exceeded\n", STACK_CAPACITY); + } + + goto end; + } + + if (profiler->called == 0 && !profiler->calibrated) { + calibrate(profiler); + } + spx_profiler_metric_values_t cur_metric_values; spx_metric_collector_collect( @@ -242,26 +263,13 @@ void spx_profiler_call_start( profiler->called++; - if ( - profiler->stack.depth >= STACK_CAPACITY || - (profiler->max_depth > 0 && profiler->stack.depth >= profiler->max_depth) - ) { - profiler->active = 0; - if (profiler->stack.depth == STACK_CAPACITY) { - fprintf(stderr, "SPX: STACK_CAPACITY (%d) exceeded\n", STACK_CAPACITY); - } - } else { - profiler->active = 1; - } - - if (!profiler->active) { - goto end; - } + spx_php_function_t function; + spx_php_current_function(&function); stack_frame_t * frame = &profiler->stack.frames[profiler->stack.depth]; frame->func_table_entry = func_table_get_entry( &profiler->func_table, - function + &function ); if (!frame->func_table_entry) { @@ -273,21 +281,23 @@ void spx_profiler_call_start( spx_profiler_event_t event; fill_event( + &event, profiler, SPX_PROFILER_EVENT_CALL_START, profiler->stack.depth > 0 ? - &profiler->stack.frames[profiler->stack.depth - 1].func_table_entry->function : NULL + profiler->stack.frames[profiler->stack.depth - 1].func_table_entry : NULL , - &profiler->stack.frames[profiler->stack.depth].func_table_entry->function, - NULL, + profiler->stack.frames[profiler->stack.depth].func_table_entry, NULL, - &event + NULL ); if (profiler->reporter->notify(profiler->reporter, &event) == SPX_PROFILER_REPORTER_COST_HEAVY) { spx_metric_collector_noise_barrier(profiler->metric_collector); } + spx_metric_collector_add_fixed_noise(profiler->metric_collector, profiler->call_start_noise.values); + end: profiler->stack.depth++; } @@ -300,6 +310,10 @@ void spx_profiler_call_end(spx_profiler_t * profiler) profiler->stack.depth--; + if (!profiler->active) { + return; + } + spx_profiler_metric_values_t cur_metric_values; spx_metric_collector_collect( @@ -312,10 +326,6 @@ void spx_profiler_call_end(spx_profiler_t * profiler) METRIC_VALUES_SUB(profiler->cum_metric_values, profiler->first_metric_values); METRIC_VALUES_MAX(profiler->max_metric_values, cur_metric_values); - if (!profiler->active) { - return; - } - stack_frame_t * frame = &profiler->stack.frames[profiler->stack.depth]; if (!frame->func_table_entry) { return; @@ -329,55 +339,55 @@ void spx_profiler_call_end(spx_profiler_t * profiler) spx_profiler_metric_values_t exc_metric_values = inc_metric_values; METRIC_VALUES_SUB(exc_metric_values, frame->children_metric_values); - int i, cyclic = 0; + size_t cycle_depth = 0; + int i; for (i = profiler->stack.depth - 1; i >= 0; i--) { stack_frame_t * parent_frame = &profiler->stack.frames[i]; if (!parent_frame->func_table_entry) { continue; } + if (i == profiler->stack.depth - 1) { + METRIC_VALUES_ADD(parent_frame->children_metric_values, inc_metric_values); + } + if (parent_frame->func_table_entry == entry) { - cyclic = 1; + cycle_depth++; - break; + if (cycle_depth == 1) { + METRIC_VALUES_SUB(parent_frame->children_metric_values, exc_metric_values); + } } - - METRIC_VALUES_ADD(parent_frame->children_metric_values, exc_metric_values); } entry->stats.called++; - if (cyclic) { - size_t cycle_depth = 0; - for (i = 0; i < profiler->stack.depth; i++) { - if (profiler->stack.frames[i].func_table_entry == entry) { - cycle_depth++; - } - } + if (entry->stats.max_cycle_depth < cycle_depth) { + entry->stats.max_cycle_depth = cycle_depth; + } - if (entry->stats.max_cycle_depth < cycle_depth) { - entry->stats.max_cycle_depth = cycle_depth; - } - } else { + if (cycle_depth == 0) { METRIC_VALUES_ADD(entry->stats.inc, inc_metric_values); METRIC_VALUES_ADD(entry->stats.exc, exc_metric_values); } spx_profiler_event_t event; fill_event( + &event, profiler, SPX_PROFILER_EVENT_CALL_END, profiler->stack.depth > 0 ? - &profiler->stack.frames[profiler->stack.depth - 1].func_table_entry->function : NULL + profiler->stack.frames[profiler->stack.depth - 1].func_table_entry : NULL , - &profiler->stack.frames[profiler->stack.depth].func_table_entry->function, + profiler->stack.frames[profiler->stack.depth].func_table_entry, &inc_metric_values, - &exc_metric_values, - &event + &exc_metric_values ); if (profiler->reporter->notify(profiler->reporter, &event) == SPX_PROFILER_REPORTER_COST_HEAVY) { spx_metric_collector_noise_barrier(profiler->metric_collector); } + + spx_metric_collector_add_fixed_noise(profiler->metric_collector, profiler->call_end_noise.values); } void spx_profiler_finalize(spx_profiler_t * profiler) @@ -393,10 +403,66 @@ void spx_profiler_finalize(spx_profiler_t * profiler) profiler->finalized = 1; spx_profiler_event_t event; - fill_event(profiler, SPX_PROFILER_EVENT_FINALIZE, NULL, NULL, NULL, NULL, &event); + fill_event(&event, profiler, SPX_PROFILER_EVENT_FINALIZE, NULL, NULL, NULL, NULL); profiler->reporter->notify(profiler->reporter, &event); } +static spx_profiler_reporter_cost_t null_reporter_notify( + spx_profiler_reporter_t * reporter, + const spx_profiler_event_t * event +) { + return SPX_PROFILER_REPORTER_COST_LIGHT; +} + +static void calibrate(spx_profiler_t * profiler) +{ + profiler->calibrated = 1; + + spx_profiler_reporter_t null_reporter = { + null_reporter_notify, + NULL + }; + + spx_profiler_reporter_t * const orig_reporter = profiler->reporter; + profiler->reporter = &null_reporter; + + const size_t iter_count = 1000000; + int i; + size_t start, avg_noise; + + start = spx_resource_stats_cpu_time(); + + for (i = 0; i < iter_count; i++) { + spx_profiler_call_start(profiler); + if (profiler->stack.depth > 5) { + profiler->stack.depth = 5; + } + } + + avg_noise = (spx_resource_stats_cpu_time() - start) / iter_count; + + profiler->call_start_noise.values[SPX_METRIC_WALL_TIME] = avg_noise; + profiler->call_start_noise.values[SPX_METRIC_CPU_TIME] = avg_noise; + + start = spx_resource_stats_cpu_time(); + + for (i = 0; i < iter_count; i++) { + spx_profiler_call_end(profiler); + profiler->stack.depth++; + } + + avg_noise = (spx_resource_stats_cpu_time() - start) / iter_count; + + profiler->call_end_noise.values[SPX_METRIC_WALL_TIME] = avg_noise; + profiler->call_end_noise.values[SPX_METRIC_CPU_TIME] = avg_noise; + + profiler->reporter = orig_reporter; + profiler->called = 0; + profiler->stack.depth = 0; + profiler->func_table.size = 0; + spx_hset_reset(profiler->func_table.hset); +} + static unsigned long func_table_entry_hash(const void * v) { return ((const spx_profiler_func_table_entry_t *) v)->function.hash_code; @@ -464,11 +530,13 @@ static spx_profiler_func_table_entry_t * func_table_get_entry( func_table->size++; if (func_table->size == FUNC_TABLE_CAPACITY) { - fprintf(stderr, "SPX: FUNC_TABLE_CAPACITY (%d) exceeded\n", FUNC_TABLE_CAPACITY); + fprintf(stderr, "SPX: FUNC_TABLE_CAPACITY (%d) reached\n", FUNC_TABLE_CAPACITY); } - spx_profiler_func_table_entry_t * entry = &func_table->entries[func_table->size - 1]; + const size_t idx = func_table->size - 1; + spx_profiler_func_table_entry_t * entry = &func_table->entries[idx]; + entry->idx = idx; entry->function = *function; /* @@ -494,13 +562,13 @@ static spx_profiler_func_table_entry_t * func_table_get_entry( } static void fill_event( + spx_profiler_event_t * event, const spx_profiler_t * profiler, spx_profiler_event_type_t type, - const spx_php_function_t * caller, - const spx_php_function_t * callee, + const spx_profiler_func_table_entry_t * caller, + const spx_profiler_func_table_entry_t * callee, const spx_profiler_metric_values_t * inc, - const spx_profiler_metric_values_t * exc, - spx_profiler_event_t * event + const spx_profiler_metric_values_t * exc ) { event->type = type; diff --git a/src/spx_profiler.h b/src/spx_profiler.h index 12f8b8d..18438ff 100644 --- a/src/spx_profiler.h +++ b/src/spx_profiler.h @@ -19,6 +19,7 @@ typedef struct { } spx_profiler_func_stats_t; typedef struct { + size_t idx; spx_php_function_t function; spx_profiler_func_stats_t stats; } spx_profiler_func_table_entry_t; @@ -46,8 +47,8 @@ typedef struct { size_t depth; - const spx_php_function_t * caller; - const spx_php_function_t * callee; + const spx_profiler_func_table_entry_t * caller; + const spx_profiler_func_table_entry_t * callee; const spx_profiler_metric_values_t * inc; const spx_profiler_metric_values_t * exc; @@ -69,14 +70,12 @@ typedef spx_profiler_reporter_cost_t (*spx_profiler_reporter_notify_func_t) ( typedef void (*spx_profiler_reporter_destroy_func_t) (struct spx_profiler_reporter_t * reporter); typedef struct spx_profiler_reporter_t { - spx_output_stream_t * output; spx_profiler_reporter_notify_func_t notify; spx_profiler_reporter_destroy_func_t destroy; } spx_profiler_reporter_t; spx_profiler_reporter_t * spx_profiler_reporter_create( size_t size, - spx_output_stream_t * output, spx_profiler_reporter_notify_func_t notify, spx_profiler_reporter_destroy_func_t destroy ); @@ -93,11 +92,7 @@ spx_profiler_t * spx_profiler_create( void spx_profiler_destroy(spx_profiler_t * profiler); -void spx_profiler_call_start( - spx_profiler_t * profiler, - const spx_php_function_t * function -); - +void spx_profiler_call_start(spx_profiler_t * profiler); void spx_profiler_call_end(spx_profiler_t * profiler); void spx_profiler_finalize(spx_profiler_t * profiler); diff --git a/src/spx_reporter_cg.c b/src/spx_reporter_cg.c deleted file mode 100644 index 4bb39eb..0000000 --- a/src/spx_reporter_cg.c +++ /dev/null @@ -1,222 +0,0 @@ -#include -#include "spx_reporter_cg.h" - -/* - -See http://valgrind.org/docs/manual/cl-format.html for full details on callgrind format. -What is implemented here: - -HEADER -# callgrind format -[for each metric] -event: : -[end for] -events: - -fl= -fn= - - -fl= -fn= -cfi= -cfn= -calls=1 - - -*/ - -#define BUFFER_CAPACITY 16384 - -typedef struct { - const spx_php_function_t * caller; - const spx_php_function_t * callee; - spx_profiler_metric_values_t inc; - spx_profiler_metric_values_t exc; -} buffer_entry_t; - -typedef struct { - spx_profiler_reporter_t base; - - int first; - size_t buffer_size; - buffer_entry_t buffer[BUFFER_CAPACITY]; -} cg_reporter_t; - -static spx_profiler_reporter_cost_t cg_notify(spx_profiler_reporter_t * reporter, const spx_profiler_event_t * event); - -static void flush_buffer(cg_reporter_t * reporter, const int * enabled_metrics); - -static void print_header(spx_output_stream_t * output, const int * enabled_metrics); - -static void print_call( - spx_output_stream_t * output, - const int * enabled_metrics, - const spx_php_function_t * caller, - const spx_php_function_t * callee, - const spx_profiler_metric_values_t * inc, - const spx_profiler_metric_values_t * exc -); - -spx_profiler_reporter_t * spx_reporter_cg_create(spx_output_stream_t * output) -{ - cg_reporter_t * reporter = (cg_reporter_t *) spx_profiler_reporter_create(sizeof(*reporter), output, cg_notify, NULL); - if (!reporter) { - return NULL; - } - - reporter->first = 1; - reporter->buffer_size = 0; - - return (spx_profiler_reporter_t *) reporter; -} - -static spx_profiler_reporter_cost_t cg_notify(spx_profiler_reporter_t * base_reporter, const spx_profiler_event_t * event) -{ - if (event->type == SPX_PROFILER_EVENT_CALL_START) { - return SPX_PROFILER_REPORTER_COST_LIGHT; - } - - cg_reporter_t * reporter = (cg_reporter_t *) base_reporter; - - if (event->type == SPX_PROFILER_EVENT_CALL_END) { - buffer_entry_t * current = &reporter->buffer[reporter->buffer_size]; - - current->caller = event->caller; - current->callee = event->callee; - current->inc = *event->inc; - current->exc = *event->exc; - - reporter->buffer_size++; - - if (reporter->buffer_size < BUFFER_CAPACITY) { - return SPX_PROFILER_REPORTER_COST_LIGHT; - } - } - - flush_buffer(reporter, event->enabled_metrics); - - return SPX_PROFILER_REPORTER_COST_HEAVY; -} - -static void flush_buffer(cg_reporter_t * reporter, const int * enabled_metrics) -{ - if (reporter->first) { - reporter->first = 0; - - print_header(reporter->base.output, enabled_metrics); - } - - size_t i; - for (i = 0; i < reporter->buffer_size; i++) { - print_call( - reporter->base.output, - enabled_metrics, - reporter->buffer[i].caller, - reporter->buffer[i].callee, - &reporter->buffer[i].inc, - &reporter->buffer[i].exc - ); - } - - reporter->buffer_size = 0; -} - -static void print_header(spx_output_stream_t * output, const int * enabled_metrics) -{ - spx_output_stream_print(output, "# callgrind format\n"); - - SPX_METRIC_FOREACH(i, { - if (!enabled_metrics[i]) { - continue; - } - - spx_output_stream_printf( - output, - "event: %s : %s\n", - spx_metrics_info[i].short_name, - spx_metrics_info[i].name - ); - }); - - spx_output_stream_print(output, "events: "); - - SPX_METRIC_FOREACH(i, { - if (!enabled_metrics[i]) { - continue; - } - - spx_output_stream_printf(output, "%s ", spx_metrics_info[i].short_name); - }); - - spx_output_stream_print(output, "\n"); -} - -static void print_call( - spx_output_stream_t * output, - const int * enabled_metrics, - const spx_php_function_t * caller, - const spx_php_function_t * callee, - const spx_profiler_metric_values_t * inc, - const spx_profiler_metric_values_t * exc -) { - spx_output_stream_printf( - output, - "fl=%s\nfn=%s%s%s\n", - callee->file_name, - callee->class_name, - callee->call_type, - callee->func_name - ); - - spx_output_stream_printf(output, "%d", callee->line); - - SPX_METRIC_FOREACH(i, { - if (!enabled_metrics[i]) { - continue; - } - - spx_output_stream_printf(output, " %d", (int) exc->values[i]); - }); - - spx_output_stream_print(output, "\n\n"); - - if (!caller) { - return; - } - - spx_output_stream_printf( - output, - "fl=%s\nfn=%s%s%s\n", - caller->file_name, - caller->class_name, - caller->call_type, - caller->func_name - ); - - spx_output_stream_printf( - output, - "cfi=%s\ncfn=%s%s%s\n", - callee->file_name, - callee->class_name, - callee->call_type, - callee->func_name - ); - - spx_output_stream_printf( - output, - "calls=1 %d\n", - callee->line - ); - - spx_output_stream_printf(output, "%d", caller->line); - SPX_METRIC_FOREACH(i, { - if (!enabled_metrics[i]) { - continue; - } - - spx_output_stream_printf(output, " %d", (int) inc->values[i]); - }); - - spx_output_stream_print(output, "\n\n"); -} diff --git a/src/spx_reporter_cg.h b/src/spx_reporter_cg.h deleted file mode 100644 index f16ed73..0000000 --- a/src/spx_reporter_cg.h +++ /dev/null @@ -1,9 +0,0 @@ -#ifndef SPX_REPORTER_CG_H_DEFINED -#define SPX_REPORTER_CG_H_DEFINED - -#include "spx_output_stream.h" -#include "spx_profiler.h" - -spx_profiler_reporter_t * spx_reporter_cg_create(spx_output_stream_t * output); - -#endif /* SPX_REPORTER_CG_H_DEFINED */ diff --git a/src/spx_reporter_fp.c b/src/spx_reporter_fp.c index 91b9f0f..a9bb031 100644 --- a/src/spx_reporter_fp.c +++ b/src/spx_reporter_fp.c @@ -1,8 +1,12 @@ #include #include +#include + #include "spx_reporter_fp.h" #include "spx_resource_stats.h" +#include "spx_output_stream.h" +#include "spx_stdio.h" #include "spx_thread.h" typedef struct { @@ -14,6 +18,12 @@ typedef struct { size_t limit; int live; + spx_output_stream_t * output; + struct { + int stdout_fd; + int stderr_fd; + } fd_backup; + size_t last_ts_ms; size_t last_line_count; const spx_profiler_func_table_entry_t ** top_entries; @@ -29,7 +39,6 @@ static int entry_cmp_r(const void * a, const void * b, const fp_reporter_t * rep static size_t print_report(fp_reporter_t * reporter, const spx_profiler_event_t * event); spx_profiler_reporter_t * spx_reporter_fp_create( - spx_output_stream_t * output, spx_metric_t focus, int inc, int rel, @@ -38,7 +47,6 @@ spx_profiler_reporter_t * spx_reporter_fp_create( ) { fp_reporter_t * reporter = (fp_reporter_t *) spx_profiler_reporter_create( sizeof(*reporter), - output, fp_notify, fp_destroy ); @@ -51,19 +59,47 @@ spx_profiler_reporter_t * spx_reporter_fp_create( reporter->inc = inc; reporter->rel = rel; reporter->limit = limit; - reporter->live = live; + reporter->live = live && isatty(STDOUT_FILENO); + + reporter->fd_backup.stdout_fd = -1; + reporter->fd_backup.stderr_fd = -1; + reporter->output = NULL; + reporter->top_entries = NULL; + + if (reporter->live) { + reporter->fd_backup.stdout_fd = spx_stdio_disable(STDOUT_FILENO); + if (reporter->fd_backup.stdout_fd == -1) { + goto error; + } + + reporter->fd_backup.stderr_fd = spx_stdio_disable(STDERR_FILENO); + if (reporter->fd_backup.stderr_fd == -1) { + goto error; + } + + reporter->output = spx_output_stream_dopen(reporter->fd_backup.stdout_fd, 0); + } else { + reporter->output = spx_output_stream_dopen(STDERR_FILENO, 0); + } + + if (!reporter->output) { + goto error; + } reporter->last_ts_ms = 0; reporter->last_line_count = 0; reporter->top_entries = malloc(limit * sizeof(*reporter->top_entries)); if (!reporter->top_entries) { - free(reporter); - - return NULL; + goto error; } return (spx_profiler_reporter_t *) reporter; + +error: + spx_profiler_reporter_destroy((spx_profiler_reporter_t *)reporter); + + return NULL; } static spx_profiler_reporter_cost_t fp_notify(spx_profiler_reporter_t * reporter, const spx_profiler_event_t * event) @@ -87,10 +123,10 @@ static spx_profiler_reporter_cost_t fp_notify(spx_profiler_reporter_t * reporter } if (fp_reporter->last_line_count > 0) { - spx_output_stream_print(fp_reporter->base.output, "\x0D\x1B[2K"); + spx_output_stream_print(fp_reporter->output, "\x0D\x1B[2K"); size_t i; for (i = 0; i < fp_reporter->last_line_count; i++) { - spx_output_stream_print(fp_reporter->base.output, "\x1B[1A\x1B[2K"); + spx_output_stream_print(fp_reporter->output, "\x1B[1A\x1B[2K"); } } @@ -103,7 +139,21 @@ static void fp_destroy(spx_profiler_reporter_t * reporter) { fp_reporter_t * fp_reporter = (fp_reporter_t *) reporter; - free(fp_reporter->top_entries); + if (fp_reporter->top_entries) { + free(fp_reporter->top_entries); + } + + if (fp_reporter->output) { + spx_output_stream_close(fp_reporter->output); + } + + if (fp_reporter->fd_backup.stdout_fd != -1) { + spx_stdio_restore(STDOUT_FILENO, fp_reporter->fd_backup.stdout_fd); + } + + if (fp_reporter->fd_backup.stderr_fd != -1) { + spx_stdio_restore(STDERR_FILENO, fp_reporter->fd_backup.stderr_fd); + } } static int entry_cmp(const void * a, const void * b) @@ -192,31 +242,31 @@ static size_t print_report(fp_reporter_t * reporter, const spx_profiler_event_t entry_cmp ); - spx_output_stream_print(reporter->base.output, "\n*** SPX Report ***\n\nGlobal stats:\n\n"); + spx_output_stream_print(reporter->output, "\n*** SPX Report ***\n\nGlobal stats:\n\n"); size_t line_count = 5; - spx_output_stream_printf(reporter->base.output, " %-20s: ", "Called functions"); + spx_output_stream_printf(reporter->output, " %-20s: ", "Called functions"); spx_fmt_print_value( - reporter->base.output, + reporter->output, SPX_FMT_QUANTITY, event->called ); - spx_output_stream_print(reporter->base.output, "\n"); + spx_output_stream_print(reporter->output, "\n"); line_count++; - spx_output_stream_printf(reporter->base.output, " %-20s: ", "Distinct functions"); + spx_output_stream_printf(reporter->output, " %-20s: ", "Distinct functions"); spx_fmt_print_value( - reporter->base.output, + reporter->output, SPX_FMT_QUANTITY, event->func_table.size ); if (event->func_table.size == event->func_table.capacity) { - spx_output_stream_print(reporter->base.output, "+"); + spx_output_stream_print(reporter->output, "+"); } - spx_output_stream_print(reporter->base.output, "\n\n"); + spx_output_stream_print(reporter->output, "\n\n"); line_count += 2; SPX_METRIC_FOREACH(i, { @@ -224,18 +274,18 @@ static size_t print_report(fp_reporter_t * reporter, const spx_profiler_event_t continue; } - spx_output_stream_printf(reporter->base.output, " %-20s: ", spx_metrics_info[i].name); + spx_output_stream_printf(reporter->output, " %-20s: ", spx_metrics_info[i].name); spx_fmt_print_value( - reporter->base.output, + reporter->output, spx_metrics_info[i].type, event->max->values[i] ); - spx_output_stream_print(reporter->base.output, "\n"); + spx_output_stream_print(reporter->output, "\n"); line_count++; }); - spx_output_stream_print(reporter->base.output, "\nFlat profile:\n\n"); + spx_output_stream_print(reporter->output, "\nFlat profile:\n\n"); line_count += 3; spx_fmt_row_t * fmt_row = spx_fmt_row_create(); @@ -248,7 +298,7 @@ static size_t print_report(fp_reporter_t * reporter, const spx_profiler_event_t spx_fmt_row_add_tcell(fmt_row, 2, spx_metrics_info[i].name); }); - spx_fmt_row_print(fmt_row, reporter->base.output); + spx_fmt_row_print(fmt_row, reporter->output); spx_fmt_row_reset(fmt_row); SPX_METRIC_FOREACH(i, { @@ -272,8 +322,8 @@ static size_t print_report(fp_reporter_t * reporter, const spx_profiler_event_t spx_fmt_row_add_tcell(fmt_row, 1, "Called"); spx_fmt_row_add_tcell(fmt_row, 0, "Function"); - spx_fmt_row_print(fmt_row, reporter->base.output); - spx_fmt_row_print_sep(fmt_row, reporter->base.output); + spx_fmt_row_print(fmt_row, reporter->output); + spx_fmt_row_print_sep(fmt_row, reporter->output); spx_fmt_row_reset(fmt_row); line_count += 3; @@ -326,7 +376,7 @@ static size_t print_report(fp_reporter_t * reporter, const spx_profiler_event_t spx_fmt_row_add_tcell(fmt_row, 0, func_name); - spx_fmt_row_print(fmt_row, reporter->base.output); + spx_fmt_row_print(fmt_row, reporter->output); spx_fmt_row_reset(fmt_row); } @@ -334,8 +384,8 @@ static size_t print_report(fp_reporter_t * reporter, const spx_profiler_event_t spx_fmt_row_destroy(fmt_row); - spx_output_stream_print(reporter->base.output, "\n"); - spx_output_stream_flush(reporter->base.output); + spx_output_stream_print(reporter->output, "\n"); + spx_output_stream_flush(reporter->output); line_count++; diff --git a/src/spx_reporter_fp.h b/src/spx_reporter_fp.h index 25f9d3e..7fb2787 100644 --- a/src/spx_reporter_fp.h +++ b/src/spx_reporter_fp.h @@ -1,11 +1,9 @@ #ifndef SPX_REPORTER_FP_H_DEFINED #define SPX_REPORTER_FP_H_DEFINED -#include "spx_output_stream.h" #include "spx_profiler.h" spx_profiler_reporter_t * spx_reporter_fp_create( - spx_output_stream_t * output, spx_metric_t focus, int inc, int rel, diff --git a/src/spx_reporter_full.c b/src/spx_reporter_full.c new file mode 100644 index 0000000..4523b1d --- /dev/null +++ b/src/spx_reporter_full.c @@ -0,0 +1,580 @@ +#include +#include +#include +#include + +#include +#include +#include +#include +#include + +#include "spx_reporter_full.h" +#include "spx_php.h" +#include "spx_output_stream.h" +#include "spx_str_builder.h" +#include "spx_utils.h" + +#define BUFFER_CAPACITY 16384 + +typedef struct { + size_t function_idx; + int start; + spx_profiler_metric_values_t metric_values; +} buffer_entry_t; + +typedef struct { + char * key; + size_t exec_ts; + char * hostname; + pid_t process_pid; + pid_t process_tid; + char * process_pwd; + int cli; + char * cli_command_line; + char * http_request_uri; + char * http_method; + char * http_host; + size_t wall_time_ms; + size_t peak_memory_usage; + size_t called_function_count; + size_t call_count; + size_t recorded_call_count; + size_t time_res_us; + int enabled_metrics[SPX_METRIC_COUNT]; +} metadata_t; + +typedef struct { + spx_profiler_reporter_t base; + + char metadata_file_name[512]; + metadata_t * metadata; + spx_output_stream_t * output; + + size_t time_res_us; + + size_t buffer_size; + buffer_entry_t buffer[BUFFER_CAPACITY]; + + spx_str_builder_t * str_builder; +} full_reporter_t; + +static spx_profiler_reporter_cost_t full_notify( + spx_profiler_reporter_t * reporter, + const spx_profiler_event_t * event +); + +static void full_destroy(spx_profiler_reporter_t * reporter); +static void flush_buffer(full_reporter_t * reporter, const int * enabled_metrics); +static void finalize(full_reporter_t * reporter, const spx_profiler_event_t * event); + +static metadata_t * metadata_create(); +static void metadata_destroy(metadata_t * metadata); +static int metadata_save(const metadata_t * metadata, const char * file_name); + +size_t spx_reporter_full_metadata_list_files( + const char * data_dir, + void (*callback) (const char *, size_t) +) { + DIR * dir = opendir(data_dir); + if (!dir) { + return 0; + } + + char file_path[512]; + size_t count = 0; + const struct dirent * entry; + while ((entry = readdir(dir)) != NULL) { + if (entry->d_type != DT_REG) { + continue; + } + + if (!spx_utils_str_ends_with(entry->d_name, ".json")) { + continue; + } + + snprintf( + file_path, + sizeof(file_path), + "%s/%s", + data_dir, + entry->d_name + ); + + callback(file_path, count); + count++; + } + + closedir(dir); + + return count; +} + +int spx_reporter_full_metadata_get_file_name( + const char * data_dir, + const char * key, + char * file_name, + size_t size +) { + return snprintf( + file_name, + size, + "%s/%s.json", + data_dir, + key + ); +} + +int spx_reporter_full_get_file_name( + const char * data_dir, + const char * key, + char * file_name, + size_t size +) { + return snprintf( + file_name, + size, + "%s/%s.txt.gz", + data_dir, + key + ); +} + +spx_profiler_reporter_t * spx_reporter_full_create(const char * data_dir, size_t time_res_us) +{ + full_reporter_t * reporter = (full_reporter_t *) spx_profiler_reporter_create( + sizeof(*reporter), + full_notify, + full_destroy + ); + + if (!reporter) { + return NULL; + } + + reporter->metadata = NULL; + reporter->output = NULL; + reporter->str_builder = NULL; + + reporter->metadata = metadata_create(); + if (!reporter->metadata) { + goto error; + } + + char file_name[512]; + spx_reporter_full_get_file_name( + data_dir, + reporter->metadata->key, + file_name, + sizeof(file_name) + ); + + spx_reporter_full_metadata_get_file_name( + data_dir, + reporter->metadata->key, + reporter->metadata_file_name, + sizeof(reporter->metadata_file_name) + ); + + (void) mkdir(data_dir, 0777); + reporter->output = spx_output_stream_open(file_name, 1); + if (!reporter->output) { + goto error; + } + + reporter->str_builder = spx_str_builder_create(8 * 1024); + if (!reporter->str_builder) { + goto error; + } + + reporter->time_res_us = time_res_us; + reporter->buffer_size = 0; + + spx_output_stream_print(reporter->output, "[events]\n"); + + return (spx_profiler_reporter_t *) reporter; + +error: + spx_profiler_reporter_destroy((spx_profiler_reporter_t *)reporter); + + return NULL; +} + +static spx_profiler_reporter_cost_t full_notify( + spx_profiler_reporter_t * base_reporter, + const spx_profiler_event_t * event +) { + full_reporter_t * reporter = (full_reporter_t *) base_reporter; + + if (event->type == SPX_PROFILER_EVENT_CALL_END) { + reporter->metadata->call_count++; + } + + if (event->type != SPX_PROFILER_EVENT_FINALIZE) { + const buffer_entry_t * previous = NULL; + if (reporter->buffer_size > 0) { + previous = &reporter->buffer[reporter->buffer_size - 1]; + } + + if ( + reporter->time_res_us > 0 + && previous + && previous->start + && event->type == SPX_PROFILER_EVENT_CALL_END + && ( + event->cum->values[SPX_METRIC_WALL_TIME] + - previous->metric_values.values[SPX_METRIC_WALL_TIME] + < 1000 * reporter->time_res_us + ) + ) { + reporter->buffer_size--; + + return SPX_PROFILER_REPORTER_COST_LIGHT; + } + + if (event->type == SPX_PROFILER_EVENT_CALL_END) { + reporter->metadata->recorded_call_count++; + } + + buffer_entry_t * current = &reporter->buffer[reporter->buffer_size]; + + current->function_idx = event->callee->idx; + current->start = event->type == SPX_PROFILER_EVENT_CALL_START; + current->metric_values = *event->cum; + + reporter->buffer_size++; + + if (reporter->buffer_size < BUFFER_CAPACITY) { + return SPX_PROFILER_REPORTER_COST_LIGHT; + } + } + + flush_buffer(reporter, event->enabled_metrics); + + if (event->type == SPX_PROFILER_EVENT_FINALIZE) { + finalize(reporter, event); + } + + return SPX_PROFILER_REPORTER_COST_HEAVY; +} + +static void full_destroy(spx_profiler_reporter_t * base_reporter) +{ + full_reporter_t * reporter = (full_reporter_t *) base_reporter; + + if (reporter->metadata) { + metadata_destroy(reporter->metadata); + } + + if (reporter->output) { + spx_output_stream_close(reporter->output); + } + + if (reporter->str_builder) { + spx_str_builder_destroy(reporter->str_builder); + } +} + +static void flush_buffer(full_reporter_t * reporter, const int * enabled_metrics) +{ + spx_str_builder_reset(reporter->str_builder); + + size_t i; + for (i = 0; i < reporter->buffer_size; i++) { + const buffer_entry_t * current = &reporter->buffer[i]; + + spx_str_builder_append_long(reporter->str_builder, current->function_idx); + spx_str_builder_append_char(reporter->str_builder, ' '); + spx_str_builder_append_char(reporter->str_builder, current->start ? '1' : '0'); + + SPX_METRIC_FOREACH(i, { + if (!enabled_metrics[i]) { + continue; + } + + spx_str_builder_append_char(reporter->str_builder, ' '); + spx_str_builder_append_double(reporter->str_builder, current->metric_values.values[i], 4); + }); + + spx_str_builder_append_str(reporter->str_builder, "\n"); + + if (spx_str_builder_remaining(reporter->str_builder) < 128) { + spx_output_stream_print(reporter->output, spx_str_builder_str(reporter->str_builder)); + spx_str_builder_reset(reporter->str_builder); + } + } + + if (spx_str_builder_size(reporter->str_builder) > 0) { + spx_output_stream_print(reporter->output, spx_str_builder_str(reporter->str_builder)); + } + + reporter->buffer_size = 0; +} + +static void finalize(full_reporter_t * reporter, const spx_profiler_event_t * event) +{ + spx_output_stream_print(reporter->output, "[functions]\n"); + + size_t i; + for (i = 0; i < event->func_table.size; i++) { + const spx_profiler_func_table_entry_t * entry = &event->func_table.entries[i]; + + spx_output_stream_printf( + reporter->output, + "%s%s%s\n", + entry->function.class_name, + entry->function.call_type, + entry->function.func_name + ); + } + + reporter->metadata->peak_memory_usage = spx_php_zend_memory_usage(); + reporter->metadata->wall_time_ms = event->cum->values[SPX_METRIC_WALL_TIME] / 1000; + + reporter->metadata->called_function_count = event->func_table.size; + reporter->metadata->time_res_us = reporter->time_res_us; + SPX_METRIC_FOREACH(i, { + reporter->metadata->enabled_metrics[i] = event->enabled_metrics[i]; + }); + + metadata_save(reporter->metadata, reporter->metadata_file_name); +} + +static metadata_t * metadata_create() +{ + metadata_t * metadata = malloc(sizeof(*metadata)); + if (!metadata) { + return NULL; + } + + metadata->exec_ts = time(NULL); + + char hostname[256]; + if (0 == gethostname(hostname, sizeof(hostname))) { + hostname[sizeof(hostname) - 1] = 0; + metadata->hostname = strdup(hostname); + } else { + metadata->hostname = strdup("n/a"); + } + + metadata->process_pid = getpid(); + metadata->process_tid = syscall(SYS_gettid); + + time_t timer; + time(&timer); + + char date[32]; + strftime( + date, + sizeof(date), + "%Y%m%d_%H%M%S", + localtime(&timer) + ); + + char key[512]; + snprintf( + key, + sizeof(key), + "spx-full-%s-%s-%d-%d", + date, + metadata->hostname, + metadata->process_pid, + rand() + ); + + metadata->key = strdup(key); + + char pwd[8 * 1024]; + metadata->process_pwd = strdup(getcwd(pwd, sizeof(pwd)) ? pwd : "n/a"); + + metadata->cli = spx_php_is_cli_sapi(); + metadata->cli_command_line = spx_php_build_command_line(); + + const char * http_request_uri = spx_php_global_array_get("_SERVER", "REQUEST_URI"); + metadata->http_request_uri = strdup(http_request_uri ? http_request_uri : "n/a"); + + const char * http_method = spx_php_global_array_get("_SERVER", "REQUEST_METHOD"); + metadata->http_method = strdup(http_method ? http_method : "n/a"); + + const char * http_host = spx_php_global_array_get("_SERVER", "HTTP_HOST"); + metadata->http_host = strdup(http_host ? http_host : "n/a"); + + metadata->call_count = 0; + metadata->recorded_call_count = 0; + + return metadata; +} + +static void metadata_destroy(metadata_t * metadata) +{ + free(metadata->key); + free(metadata->hostname); + free(metadata->process_pwd); + + free(metadata->cli_command_line); + free(metadata->http_request_uri); + free(metadata->http_method); + free(metadata->http_host); + + free(metadata); +} + +static int metadata_save(const metadata_t * metadata, const char * file_name) +{ + FILE * fp = fopen(file_name, "w"); + if (!fp) { + return -1; + } + + char buf[8 * 1024]; + + fprintf(fp, "{\n"); + + fprintf( + fp, + " \"%s\": \"%s\",\n", + "key", + spx_utils_json_escape(buf, metadata->key, sizeof(buf)) + ); + + fprintf( + fp, + " \"%s\": %lu,\n", + "exec_ts", + metadata->exec_ts + ); + + fprintf( + fp, + " \"%s\": \"%s\",\n", + "host_name", + spx_utils_json_escape(buf, metadata->hostname, sizeof(buf)) + ); + + fprintf( + fp, + " \"%s\": %d,\n", + "process_pid", + metadata->process_pid + ); + + fprintf( + fp, + " \"%s\": %d,\n", + "process_tid", + metadata->process_tid + ); + + fprintf( + fp, + " \"%s\": \"%s\",\n", + "process_pwd", + spx_utils_json_escape(buf, metadata->process_pwd, sizeof(buf)) + ); + + fprintf( + fp, + " \"%s\": %d,\n", + "cli", + metadata->cli + ); + + fprintf( + fp, + " \"%s\": \"%s\",\n", + "cli_command_line", + spx_utils_json_escape(buf, metadata->cli_command_line, sizeof(buf)) + ); + + fprintf( + fp, + " \"%s\": \"%s\",\n", + "http_request_uri", + spx_utils_json_escape(buf, metadata->http_request_uri, sizeof(buf)) + ); + + fprintf( + fp, + " \"%s\": \"%s\",\n", + "http_method", + spx_utils_json_escape(buf, metadata->http_method, sizeof(buf)) + ); + + fprintf( + fp, + " \"%s\": \"%s\",\n", + "http_host", + spx_utils_json_escape(buf, metadata->http_host, sizeof(buf)) + ); + + fprintf( + fp, + " \"%s\": %lu,\n", + "wall_time_ms", + metadata->wall_time_ms + ); + + fprintf( + fp, + " \"%s\": %lu,\n", + "peak_memory_usage", + metadata->peak_memory_usage + ); + + fprintf( + fp, + " \"%s\": %lu,\n", + "called_function_count", + metadata->called_function_count + ); + + fprintf( + fp, + " \"%s\": %lu,\n", + "call_count", + metadata->call_count + ); + + fprintf( + fp, + " \"%s\": %lu,\n", + "recorded_call_count", + metadata->recorded_call_count + ); + + fprintf( + fp, + " \"%s\": %lu,\n", + "time_res_us", + metadata->time_res_us + ); + + fprintf(fp, " \"enabled_metrics\": [\n"); + + int first = 1; + SPX_METRIC_FOREACH(i, { + if (!metadata->enabled_metrics[i]) { + continue; + } + + fprintf(fp, " "); + + if (!first) { + fprintf(fp, ","); + } else { + first = 0; + } + + fprintf( + fp, + "\"%s\"\n", + spx_metrics_info[i].key + ); + }); + + fprintf(fp, " ]\n}\n"); + + fclose(fp); + + return 0; +} diff --git a/src/spx_reporter_full.h b/src/spx_reporter_full.h new file mode 100644 index 0000000..0470e8c --- /dev/null +++ b/src/spx_reporter_full.h @@ -0,0 +1,29 @@ +#ifndef SPX_REPORTER_FULL_H_DEFINED +#define SPX_REPORTER_FULL_H_DEFINED + +#include + +#include "spx_profiler.h" + +size_t spx_reporter_full_metadata_list_files( + const char * data_dir, + void (*callback) (const char *, size_t) +); + +int spx_reporter_full_metadata_get_file_name( + const char * data_dir, + const char * key, + char * file_name, + size_t size +); + +int spx_reporter_full_get_file_name( + const char * data_dir, + const char * key, + char * file_name, + size_t size +); + +spx_profiler_reporter_t * spx_reporter_full_create(const char * data_dir, size_t res); + +#endif /* SPX_REPORTER_FULL_H_DEFINED */ diff --git a/src/spx_reporter_gte.c b/src/spx_reporter_gte.c deleted file mode 100644 index 6dfe80d..0000000 --- a/src/spx_reporter_gte.c +++ /dev/null @@ -1,115 +0,0 @@ -#include -#include "spx_reporter_gte.h" - -#define BUFFER_CAPACITY 16384 - -typedef struct { - spx_profiler_event_type_t event_type; - const spx_php_function_t * callee; - spx_profiler_metric_values_t cum; -} buffer_entry_t; - -typedef struct { - spx_profiler_reporter_t base; - - int first; - size_t buffer_size; - buffer_entry_t buffer[BUFFER_CAPACITY]; -} gte_reporter_t; - -static spx_profiler_reporter_cost_t gte_notify(spx_profiler_reporter_t * base_reporter, const spx_profiler_event_t * event); - -static void flush_buffer(gte_reporter_t * reporter); - -static char * json_escape(char * dst, const char * src, size_t limit); - -spx_profiler_reporter_t * spx_reporter_gte_create(spx_output_stream_t * output) -{ - gte_reporter_t * reporter = (gte_reporter_t *) spx_profiler_reporter_create( - sizeof(*reporter), - output, - gte_notify, - NULL - ); - - if (!reporter) { - return NULL; - } - - reporter->first = 1; - reporter->buffer_size = 0; - - return (spx_profiler_reporter_t *) reporter; -} - -static spx_profiler_reporter_cost_t gte_notify(spx_profiler_reporter_t * base_reporter, const spx_profiler_event_t * event) -{ - gte_reporter_t * reporter = (gte_reporter_t *) base_reporter; - - if (event->type != SPX_PROFILER_EVENT_FINALIZE) { - buffer_entry_t * current = &reporter->buffer[reporter->buffer_size]; - - current->event_type = event->type; - current->callee = event->callee; - current->cum = *event->cum; - - reporter->buffer_size++; - - if (reporter->buffer_size < BUFFER_CAPACITY) { - return SPX_PROFILER_REPORTER_COST_LIGHT; - } - } - - flush_buffer(reporter); - - if (event->type == SPX_PROFILER_EVENT_FINALIZE) { - spx_output_stream_print(reporter->base.output, "]"); - } - - return SPX_PROFILER_REPORTER_COST_HEAVY; -} - -static void flush_buffer(gte_reporter_t * reporter) -{ - char class_name[512]; - char func_name[512]; - - size_t i; - for (i = 0; i < reporter->buffer_size; i++) { - const buffer_entry_t * entry = &reporter->buffer[i]; - - spx_output_stream_printf( - reporter->base.output, - "%s{\"name\": \"%s%s%s\", \"cat\": \"PHP\", \"ph\": \"%s\", \"pid\": 0, \"tid\": 0, \"ts\": %lu}", - reporter->first ? "[\n" : ",\n", - json_escape(class_name, entry->callee->class_name, sizeof(class_name)), - entry->callee->call_type, - json_escape(func_name, entry->callee->func_name, sizeof(func_name)), - entry->event_type == SPX_PROFILER_EVENT_CALL_START ? "B" : "E", - (size_t) entry->cum.values[SPX_METRIC_WALL_TIME] - ); - - if (reporter->first) { - reporter->first = 0; - } - } - - reporter->buffer_size = 0; -} - -static char * json_escape(char * dst, const char * src, size_t limit) -{ - size_t i = 0; - while (*src && i < limit - 2) { - dst[i++] = *src; - if (*src == '\\') { - dst[i++] = '\\'; - } - - src++; - } - - dst[i] = 0; - - return dst; -} diff --git a/src/spx_reporter_gte.h b/src/spx_reporter_gte.h deleted file mode 100644 index ab21d13..0000000 --- a/src/spx_reporter_gte.h +++ /dev/null @@ -1,9 +0,0 @@ -#ifndef SPX_REPORTER_GTE_H_DEFINED -#define SPX_REPORTER_GTE_H_DEFINED - -#include "spx_output_stream.h" -#include "spx_profiler.h" - -spx_profiler_reporter_t * spx_reporter_gte_create(spx_output_stream_t * output); - -#endif /* SPX_REPORTER_GTE_H_DEFINED */ diff --git a/src/spx_reporter_trace.c b/src/spx_reporter_trace.c index 78cf6e0..322d193 100644 --- a/src/spx_reporter_trace.c +++ b/src/spx_reporter_trace.c @@ -1,7 +1,10 @@ #include #include +#include #include "spx_reporter_trace.h" +#include "spx_output_stream.h" +#include "spx_utils.h" #define BUFFER_CAPACITY 16384 @@ -17,16 +20,20 @@ typedef struct { typedef struct { spx_profiler_reporter_t base; + const char * file_name; + spx_output_stream_t * output; + int safe; + int first; - const int * enabled_metrics; size_t buffer_size; buffer_entry_t buffer[BUFFER_CAPACITY]; } trace_reporter_t; static spx_profiler_reporter_cost_t trace_notify(spx_profiler_reporter_t * base_reporter, const spx_profiler_event_t * event); +static void trace_destroy(spx_profiler_reporter_t * base_reporter); -static void flush_buffer(trace_reporter_t * reporter); +static void flush_buffer(trace_reporter_t * reporter, const int * enabled_metrics); static void print_header(spx_output_stream_t * output, const int * enabled_metrics); @@ -41,23 +48,33 @@ static void print_row( const spx_profiler_metric_values_t * exc_metric_values ); -spx_profiler_reporter_t * spx_reporter_trace_create(spx_output_stream_t * output, int safe) +spx_profiler_reporter_t * spx_reporter_trace_create(const char * file_name, int safe) { trace_reporter_t * reporter = (trace_reporter_t *) spx_profiler_reporter_create( sizeof(*reporter), - output, trace_notify, - NULL + trace_destroy ); if (!reporter) { return NULL; } + reporter->file_name = file_name ? file_name : "spx_trace.txt.gz"; + reporter->safe = safe; + reporter->first = 1; reporter->buffer_size = 0; + const int compressed = spx_utils_str_ends_with(reporter->file_name, ".gz"); + reporter->output = spx_output_stream_open(reporter->file_name, compressed); + if (!reporter->output) { + spx_profiler_reporter_destroy((spx_profiler_reporter_t *)reporter); + + return NULL; + } + return (spx_profiler_reporter_t *) reporter; } @@ -65,15 +82,11 @@ static spx_profiler_reporter_cost_t trace_notify(spx_profiler_reporter_t * base_ { trace_reporter_t * reporter = (trace_reporter_t *) base_reporter; - if (!reporter->enabled_metrics) { - reporter->enabled_metrics = event->enabled_metrics; - } - if (event->type != SPX_PROFILER_EVENT_FINALIZE) { buffer_entry_t * current = &reporter->buffer[reporter->buffer_size]; current->event_type = event->type; - current->function = event->callee; + current->function = &event->callee->function; current->depth = event->depth; current->cum_metric_values = *event->cum; @@ -89,17 +102,34 @@ static spx_profiler_reporter_cost_t trace_notify(spx_profiler_reporter_t * base_ } } - flush_buffer(reporter); + flush_buffer(reporter, event->enabled_metrics); + + if (event->type == SPX_PROFILER_EVENT_FINALIZE) { + fprintf( + stderr, + "\nSPX trace file: %s\n", + reporter->file_name + ); + } return SPX_PROFILER_REPORTER_COST_HEAVY; } -static void flush_buffer(trace_reporter_t * reporter) +static void trace_destroy(spx_profiler_reporter_t * base_reporter) +{ + trace_reporter_t * reporter = (trace_reporter_t *) base_reporter; + + if (reporter->output) { + spx_output_stream_close(reporter->output); + } +} + +static void flush_buffer(trace_reporter_t * reporter, const int * enabled_metrics) { if (reporter->first) { reporter->first = 0; - print_header(reporter->base.output, reporter->enabled_metrics); + print_header(reporter->output, enabled_metrics); } size_t i; @@ -107,15 +137,19 @@ static void flush_buffer(trace_reporter_t * reporter) const buffer_entry_t * entry = &reporter->buffer[i]; print_row( - reporter->base.output, + reporter->output, entry->event_type == SPX_PROFILER_EVENT_CALL_START ? "+" : "-", entry->function, entry->depth, - reporter->enabled_metrics, + enabled_metrics, &entry->cum_metric_values, entry->event_type == SPX_PROFILER_EVENT_CALL_END ? &entry->inc_metric_values : NULL, entry->event_type == SPX_PROFILER_EVENT_CALL_END ? &entry->exc_metric_values : NULL ); + + if (reporter->safe) { + spx_output_stream_flush(reporter->output); + } } reporter->buffer_size = 0; @@ -225,6 +259,4 @@ static void print_row( spx_fmt_row_print(fmt_row, output); spx_fmt_row_destroy(fmt_row); - - spx_output_stream_flush(output); } diff --git a/src/spx_reporter_trace.h b/src/spx_reporter_trace.h index 0282c59..6d9120e 100644 --- a/src/spx_reporter_trace.h +++ b/src/spx_reporter_trace.h @@ -1,9 +1,8 @@ #ifndef SPX_REPORTER_TRACE_H_DEFINED #define SPX_REPORTER_TRACE_H_DEFINED -#include "spx_output_stream.h" #include "spx_profiler.h" -spx_profiler_reporter_t * spx_reporter_trace_create(spx_output_stream_t * output, int safe); +spx_profiler_reporter_t * spx_reporter_trace_create(const char * file_name, int safe); #endif /* SPX_REPORTER_TRACE_H_DEFINED */ diff --git a/src/spx_resource_stats-linux.c b/src/spx_resource_stats-linux.c index 73321e1..d3c4a36 100644 --- a/src/spx_resource_stats-linux.c +++ b/src/spx_resource_stats-linux.c @@ -13,12 +13,14 @@ #include "spx_thread.h" static SPX_THREAD_TLS struct { + int init; int io_fd; size_t io_noise; } context; void spx_resource_stats_init(void) { + context.init = 1; char io_file[64]; snprintf( io_file, @@ -33,38 +35,38 @@ void spx_resource_stats_init(void) void spx_resource_stats_shutdown(void) { + if (!context.init) { + return; + } + if (context.io_fd != -1) { close(context.io_fd); + context.io_fd = -1; } } -#define TIMESPEC_TO_US(ts) ((ts).tv_sec * 1000 * 1000 + (ts).tv_nsec / 1000) +#define TIMESPEC_TO_NS(ts) ((ts).tv_sec * 1000 * 1000 * 1000 + (ts).tv_nsec) size_t spx_resource_stats_wall_time(void) { struct timespec ts; - /* - * CLOCK_REALTIME is used here for wall time because the performance drop (observed on 3.13.0 kernel) - * with CLOCK_MONOTONIC_RAW or even CLOCK_MONOTONIC will cause more damages on accuracy than - * potential concurrent system clock adjustments. - * However it might be best to have optimal clock dispatching according to kernel version. - */ - clock_gettime(CLOCK_REALTIME, &ts); + clock_gettime(CLOCK_MONOTONIC, &ts); - return TIMESPEC_TO_US(ts); + return TIMESPEC_TO_NS(ts); } size_t spx_resource_stats_cpu_time(void) { struct timespec ts; + /* * Linux implementation of CLOCK_PROCESS_CPUTIME_ID does not require to stick * the current thread to the same CPU. */ clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &ts); - return TIMESPEC_TO_US(ts); + return TIMESPEC_TO_NS(ts); } void spx_resource_stats_io(size_t * in, size_t * out) diff --git a/src/spx_resource_stats-macos.c b/src/spx_resource_stats-macos.c index 821d9e8..2541e9e 100644 --- a/src/spx_resource_stats-macos.c +++ b/src/spx_resource_stats-macos.c @@ -19,8 +19,12 @@ size_t spx_resource_stats_wall_time(void) int ret = 0; ret = gettimeofday(&tv, NULL); if (ret == 0) { - return tv.tv_sec * 1000 * 1000 + tv.tv_usec; + return 1000 * ( + tv.tv_sec * 1000 * 1000 + + tv.tv_usec + ); } + return ret; } @@ -28,8 +32,11 @@ size_t spx_resource_stats_cpu_time(void) { struct rusage ru; getrusage(RUSAGE_SELF, &ru); - return (ru.ru_utime.tv_sec + ru.ru_stime.tv_sec ) * 1000 * 1000 + - (ru.ru_utime.tv_usec + ru.ru_stime.tv_usec); + + return 1000 * ( + (ru.ru_utime.tv_sec + ru.ru_stime.tv_sec ) * 1000 * 1000 + + (ru.ru_utime.tv_usec + ru.ru_stime.tv_usec) + ); } void spx_resource_stats_io(size_t * in, size_t * out) diff --git a/src/spx_str_builder.c b/src/spx_str_builder.c new file mode 100644 index 0000000..0b2c574 --- /dev/null +++ b/src/spx_str_builder.c @@ -0,0 +1,236 @@ +#include + +#include "spx_str_builder.h" + +struct spx_str_builder_t { + size_t capacity; + size_t size; + char * buffer; +}; + +#define REMAINING_CHARS(s) ((s)->capacity - (s)->size) + +spx_str_builder_t * spx_str_builder_create(size_t capacity) +{ + spx_str_builder_t * str_builder = malloc(sizeof(*str_builder)); + if (!str_builder) { + return NULL; + } + + str_builder->buffer = malloc(capacity + 1); + if (!str_builder->buffer) { + free(str_builder); + + return NULL; + } + + str_builder->capacity = capacity; + spx_str_builder_reset(str_builder); + + return str_builder; +} + +void spx_str_builder_destroy(spx_str_builder_t * str_builder) +{ + free(str_builder->buffer); + free(str_builder); +} + +void spx_str_builder_reset(spx_str_builder_t * str_builder) +{ + str_builder->size = 0; + str_builder->buffer[0] = 0; +} + +size_t spx_str_builder_capacity(const spx_str_builder_t * str_builder) +{ + return str_builder->capacity; +} + +size_t spx_str_builder_size(const spx_str_builder_t * str_builder) +{ + return str_builder->size; +} + +size_t spx_str_builder_remaining(const spx_str_builder_t * str_builder) +{ + return REMAINING_CHARS(str_builder); +} + +const char * spx_str_builder_str(const spx_str_builder_t * str_builder) +{ + return str_builder->buffer; +} + +size_t spx_str_builder_append_double(spx_str_builder_t * str_builder, double d, size_t nb_dec) +{ + const size_t remaining = REMAINING_CHARS(str_builder); + if (remaining == 0) { + return 0; + } + + char * p = str_builder->buffer + str_builder->size; + + if (d == 0) { + return spx_str_builder_append_char(str_builder, '0'); + } + + size_t dec_factor = 1; + size_t i = nb_dec; + while (i--) { + dec_factor *= 10; + } + + long v = d * dec_factor + 0.5; + int neg = v < 0; + if (neg) { + v *= -1; + } + + size_t c = 0, n = 0; + while (v != 0) { + n++; + + if (c + 1 > remaining) { + str_builder->buffer[str_builder->size] = 0; + + return 0; + } + + const char digit = (v % 10) + '0'; + + if (digit == '0' && c == 0 && n <= nb_dec) { + v /= 10; + + continue; + } + + p[c++] = digit; + + v /= 10; + + if (n == nb_dec) { + if (c + 1 > remaining) { + str_builder->buffer[str_builder->size] = 0; + + return 0; + } + + p[c++] = '.'; + } + } + + if (neg) { + if (c + 1 > remaining) { + str_builder->buffer[str_builder->size] = 0; + + return 0; + } + + p[c++] = '-'; + } + + p[c] = 0; + + for (i = 0; i < c / 2; i++) { + const size_t opp = c - i - 1; + + p[i] ^= p[opp]; + p[opp] ^= p[i]; + p[i] ^= p[opp]; + } + + str_builder->size += c; + + return c; +} + +size_t spx_str_builder_append_long(spx_str_builder_t * str_builder, long l) +{ + const size_t remaining = REMAINING_CHARS(str_builder); + if (remaining == 0) { + return 0; + } + + char * p = str_builder->buffer + str_builder->size; + + if (l == 0) { + return spx_str_builder_append_char(str_builder, '0'); + } + + long v = l; + int neg = v < 0; + if (neg) { + v *= -1; + } + + size_t c = 0; + while (v != 0) { + if (c + 1 > remaining) { + str_builder->buffer[str_builder->size] = 0; + + return 0; + } + + p[c++] = (v % 10) + '0'; + v /= 10; + } + + if (neg) { + if (c + 1 > remaining) { + str_builder->buffer[str_builder->size] = 0; + + return 0; + } + + p[c++] = '-'; + } + + p[c] = 0; + + size_t i; + for (i = 0; i < c / 2; i++) { + const size_t opp = c - i - 1; + + p[i] ^= p[opp]; + p[opp] ^= p[i]; + p[i] ^= p[opp]; + } + + str_builder->size += c; + + return c; +} + +size_t spx_str_builder_append_str(spx_str_builder_t * str_builder, const char * str) +{ + char * p = str_builder->buffer + str_builder->size; + size_t c = 0; + while (*str) { + if (REMAINING_CHARS(str_builder) == 0) { + str_builder->buffer[str_builder->size] = 0; + + return 0; + } + + p[c++] = *str; + str++; + } + + p[c] = 0; + str_builder->size += c; + + return c; +} + +size_t spx_str_builder_append_char(spx_str_builder_t * str_builder, char c) +{ + if (REMAINING_CHARS(str_builder) == 0) { + return 0; + } + + str_builder->buffer[str_builder->size++] = c; + str_builder->buffer[str_builder->size] = 0; + + return 1; +} diff --git a/src/spx_str_builder.h b/src/spx_str_builder.h new file mode 100644 index 0000000..0b75319 --- /dev/null +++ b/src/spx_str_builder.h @@ -0,0 +1,20 @@ +#ifndef SPX_STR_BUILDER_H_DEFINED +#define SPX_STR_BUILDER_H_DEFINED + +typedef struct spx_str_builder_t spx_str_builder_t; + +spx_str_builder_t * spx_str_builder_create(size_t capacity); +void spx_str_builder_destroy(spx_str_builder_t * str_builder); + +void spx_str_builder_reset(spx_str_builder_t * str_builder); +size_t spx_str_builder_capacity(const spx_str_builder_t * str_builder); +size_t spx_str_builder_size(const spx_str_builder_t * str_builder); +size_t spx_str_builder_remaining(const spx_str_builder_t * str_builder); +const char * spx_str_builder_str(const spx_str_builder_t * str_builder); + +size_t spx_str_builder_append_double(spx_str_builder_t * str_builder, double d, size_t nb_dec); +size_t spx_str_builder_append_long(spx_str_builder_t * str_builder, long l); +size_t spx_str_builder_append_str(spx_str_builder_t * str_builder, const char * str); +size_t spx_str_builder_append_char(spx_str_builder_t * str_builder, char c); + +#endif /* SPX_STR_BUILDER_H_DEFINED */ diff --git a/src/spx_utils.c b/src/spx_utils.c new file mode 100644 index 0000000..4e1053c --- /dev/null +++ b/src/spx_utils.c @@ -0,0 +1,46 @@ +#include +#include "spx_utils.h" + +char * spx_utils_json_escape(char * dst, const char * src, size_t limit) +{ + if (limit < 3) { + dst[0] = 0; + + return dst; + } + + size_t i = 0; + while (*src && i < limit - 2) { + if (*src == '\\' || *src == '"') { + dst[i++] = '\\'; + } + + dst[i++] = *src; + src++; + } + + dst[i] = 0; + + return dst; +} + +int spx_utils_str_starts_with(const char * str, const char * prefix) +{ + return 0 == strncmp(str, prefix, strlen(prefix)); +} + +int spx_utils_str_ends_with(const char * str, const char * suffix) +{ + const size_t str_len = strlen(str); + const size_t suffix_len = strlen(suffix); + + if (str_len < suffix_len) { + return 0; + } + + if (strcmp(str + str_len - suffix_len, suffix) == 0) { + return 1; + } + + return 0; +} diff --git a/src/spx_utils.h b/src/spx_utils.h index cf6068c..451d2ac 100644 --- a/src/spx_utils.h +++ b/src/spx_utils.h @@ -1,6 +1,8 @@ #ifndef SPX_UTILS_H_DEFINED #define SPX_UTILS_H_DEFINED +#include + #define SPX_UTILS_TOKENIZE_STRING(str, delim, token, size, block) \ do { \ const char * c_ = str; \ @@ -27,4 +29,8 @@ do { \ } \ } while (0) +char * spx_utils_json_escape(char * dst, const char * src, size_t limit); +int spx_utils_str_starts_with(const char * str, const char * prefix); +int spx_utils_str_ends_with(const char * str, const char * suffix); + #endif /* SPX_UTILS_H_DEFINED */ diff --git a/tests/spx_001.phpt b/tests/spx_001.phpt index e423848..764f2fb 100644 --- a/tests/spx_001.phpt +++ b/tests/spx_001.phpt @@ -15,20 +15,5 @@ SPX_KEY=dev&SPX_ENABLED=1 ---EXPECTF-- -*** SPX Report *** - -Global stats: - - Called functions : 1 - Distinct functions : 1 - - Wall Time : %s - ZE memory : %s - -Flat profile: - - Wall Time | ZE memory | - Inc. | *Exc. | Inc. | Exc. | Called | Function -----------+----------+----------+----------+----------+---------- - %s | %s | %s | %s | 1 | %s/spx_001.php +--EXPECT-- +Normal output \ No newline at end of file diff --git a/tests/spx_008.phpt b/tests/spx_008.phpt deleted file mode 100644 index 0a71ce1..0000000 --- a/tests/spx_008.phpt +++ /dev/null @@ -1,17 +0,0 @@ ---TEST-- -Specified output file ---ENV-- -return << ---CLEAN-- - ---EXPECT-- -Normal output \ No newline at end of file