EmanueleMinotto · January 29, 2015 21:01 · Jan 29, 2015
diff --git a/README.md b/README.md
@@ -0,0 +1,114 @@
+# Profiler
+This is a simple PHP profiler based on `syslog` and [ticks](http://php.net/manual/en/internals2.opcodes.ticks.php).
+
+Killer feature is that it doesn't need to be included inside statements but only prepend your scripts.
+
+
+
+
+
+
+
+## Usage
+The script is a standalone file, so you only have to include it.
+
+```php
+<?php
+require_once 'profiler.php';
+declare(ticks=1);
+
+// your code here
+?>
+```
+
+## Example
+```php
+<?php
+
+require_once 'profiler.php';
+declare(ticks=1);
+
+// production code
+
+$foo = new foo;
+
+f1();
+f3();
+
+function f1() {
+    usleep(5000);
+    f2();
+}
+
+function f2() {
+    usleep(50000);
+    f3();
+}
+
+function f3() {
+    usleep(50000);
+    f4();
+}
+
+function f4() {
+    global $foo;
+    usleep(50000);
+
+    foo::bar();
+
+    $t = function () {
+        usleep(5000);
+    };
+    $t();
+
+    $foo->bar2();
+}
+
+
+class foo {
+    static function bar() {
+        usleep(1000);
+    }
+    function bar2() {
+        usleep(1000);
+    }
+}
+
+?>
+```
+
+## Output
+Output tokens are:
+
+[`process id`][`datetime`] `total calls in stack (hypens)` `statement` : `memory used` : `time used`
+
+```
+* ubuntu apache2: [678][1970-01-01 00:00:00.05076] === profiler ===
+* ubuntu apache2: [678][1970-01-01 00:00:00.05620] f1 : 235616 : 0.007133960723877
+* ubuntu apache2: [678][1970-01-01 00:00:00.10653] - f2 : 236880 : 0.050199031829834
+* ubuntu apache2: [678][1970-01-01 00:00:00.15692] -- f3 : 238136 : 0.050237894058228
+* ubuntu apache2: [678][1970-01-01 00:00:00.15715] --- f4 : 239416 : 6.5088272094727E-5
+* ubuntu apache2: [678][1970-01-01 00:00:00.20754] --- f4 : 239416 : 0.050306081771851
+* ubuntu apache2: [678][1970-01-01 00:00:00.20888] ---- foo::bar : 241120 : 0.0011959075927734
+* ubuntu apache2: [678][1970-01-01 00:00:00.20904] --- f4 : 239600 : 0.050353050231934
+* ubuntu apache2: [678][1970-01-01 00:00:00.20921] --- f4 : 239952 : 0.050410270690918
+* ubuntu apache2: [678][1970-01-01 00:00:00.21457] ---- {closure} : 241224 : 0.0052261352539062
+* ubuntu apache2: [678][1970-01-01 00:00:00.21475] --- f4 : 240136 : 0.050458192825317
+* ubuntu apache2: [678][1970-01-01 00:00:00.21606] ---- foo->bar2 : 241984 : 0.0011999607086182
+* ubuntu apache2: [678][1970-01-01 00:00:00.21624] --- f4 : 240320 : 0.050514221191406
+* ubuntu apache2: [678][1970-01-01 00:00:00.21640] -- f3 : 238856 : 0.050291776657104
+* ubuntu apache2: [678][1970-01-01 00:00:00.21656] - f2 : 237776 : 0.050248861312866
+* ubuntu apache2: [678][1970-01-01 00:00:00.21671] f1 : 236688 : 0.00718092918396
+* ubuntu apache2: [678][1970-01-01 00:00:00.26707] f3 : 236688 : 0.10052275657654
+* ubuntu apache2: [678][1970-01-01 00:00:00.26724] - f4 : 237776 : 0.050561189651489
+* ubuntu apache2: [678][1970-01-01 00:00:00.31756] - f4 : 237776 : 0.10074710845947
+* ubuntu apache2: [678][1970-01-01 00:00:00.31893] -- foo::bar : 239296 : 0.0023877620697021
+* ubuntu apache2: [678][1970-01-01 00:00:00.31910] - f4 : 237776 : 0.10079216957092
+* ubuntu apache2: [678][1970-01-01 00:00:00.31927] - f4 : 238128 : 0.1008460521698
+* ubuntu apache2: [678][1970-01-01 00:00:00.32459] -- {closure} : 239248 : 0.010415315628052
+* ubuntu apache2: [678][1970-01-01 00:00:00.32477] - f4 : 238160 : 0.10089206695557
+* ubuntu apache2: [678][1970-01-01 00:00:00.32610] -- foo->bar2 : 239824 : 0.0024130344390869
+* ubuntu apache2: [678][1970-01-01 00:00:00.32629] - f4 : 238160 : 0.10094213485718
+* ubuntu apache2: [678][1970-01-01 00:00:00.32643] f3 : 236688 : 0.10056781768799
+$ clear && tail -n 27 /var/log/syslog
+```
diff --git a/profiler.php b/profiler.php
@@ -0,0 +1,71 @@
+<?php
+
+register_tick_function(function () {
+    /**
+     * Used for the timer.
+     * @var float
+     */
+    static $last = null;
+    /**
+     * Used to store profiles.
+     * @var array
+     */
+    static $profile = array();
+    /**
+     * This variable contains main informations about last calls.
+     * @var array
+     */
+    $backtrace = debug_backtrace();
+
+    // if there are only 2 elements we aren't in a user defined code
+    if (count($backtrace) <= 1)
+        return;
+
+    // start time isn't at invoke but when
+    // the server received request
+    if (is_null($last) && $last = $_SERVER['REQUEST_TIME_FLOAT'])
+        // used to divide instances
+        // process id is used to prevent instances mix due to requests flood
+        syslog(LOG_DEBUG, '[' . getmypid() . '][' . date('Y-m-d H:i:s', $last)
+            . substr((string) microtime(), 1, 6) . '] === profiler ==='
+        );
+
+    /**
+     * This variable contains current function definition attributes like name,
+     * class, type, file, line and args.
+     * @var string
+     */
+    $function = isset($backtrace[1]['class'])
+        ? $backtrace[1]['class'] . $backtrace[1]['type'] . $backtrace[1]['function']
+        : $backtrace[1]['function'];
+
+    if (isset($backtrace[2]))
+        /**
+         * This variable contains informations about parent (user defined)
+         * code that invoked current statement.
+         * @var string
+         */
+        $parent = isset($backtrace[2]['class'])
+            ? $backtrace[2]['class'] . $backtrace[2]['type'] . $backtrace[2]['function']
+            : $backtrace[2]['function'];
+
+    /**
+     * This variable contains microtimes.
+     * Used to render time differences.
+     * @var array
+     */
+    $profile[$function] = microtime(true) - $last + @$profile[$function];
+    // output times in the right place
+    // syntax: [{process id}][{datetime}] {position in stack (hypens)} {function} : {memory} : {seconds}
+    syslog(LOG_DEBUG, '[' . getmypid() . '][' . date('Y-m-d H:i:s')
+        . substr((string) microtime(), 1, 6) . '] '
+        . (count($backtrace) - 2 ? str_repeat('-', count($backtrace) - 2) . ' ' : null) . $function 
+        . ' : ' . memory_get_usage()
+        . ' : ' . $profile[$function]
+    );
+    /**
+     * Used to profile next request.
+     * @var float
+     */
+    $last = microtime(true);
+});