Last active
September 18, 2018 12:57
-
-
Save docteurklein/534fc94a93e654d76a9c7e377aa5c07d to your computer and use it in GitHub Desktop.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| <?php | |
| $num = floatval($argv[1] ?? '1e6'); | |
| echo "iterations: $num\n"; | |
| function noop() { | |
| } | |
| $start = microtime(true); | |
| printf("starting raw at:\t\t%.3F s\n", $start); | |
| for ($i=0; $i < $num; $i++) { | |
| noop(); | |
| } | |
| $duration = microtime(true) - $start; | |
| tideways_xhprof_enable(TIDEWAYS_XHPROF_FLAGS_MEMORY | TIDEWAYS_XHPROF_FLAGS_CPU); | |
| $start_p = microtime(true); | |
| printf("starting profiling at: \t\t%.3F s\n", $start_p); | |
| for ($i=0; $i < $num; $i++) { | |
| noop(); | |
| } | |
| $duration_p = microtime(true) - $start_p; | |
| tideways_xhprof_disable(); | |
| printf("raw:\t\t%d µs\n", $duration * 1e6); | |
| printf("profiler:\t%d µs\n", $duration_p * 1e6); | |
| printf("total overhead:\t%d µs (x%.2F)\n", ($duration_p - $duration) * 1e6, $duration_p / $duration); | |
| printf("avg overhead:\t%.3F µs\n", (($duration_p - $duration) / $num) * 1e6); |
Author
docteurklein
commented
Sep 18, 2018
•
xhprof data output:
% php -n -d extension=$HOME/work/tideways/php-xhprof-extension/modules/tideways_xhprof.so example/overhead.php 1e7|jq
{
"main()==>noop": {
"ct": 10000000,
"wt": 5005703,
"cpu": 5176896,
"mu": 128,
"pmu": 0
},
"main()==>microtime": {
"ct": 2,
"wt": 2,
"cpu": 4,
"mu": 128,
"pmu": 0
},
"main()": {
"ct": 1,
"wt": 10358666,
"cpu": 10345986,
"mu": 608,
"pmu": 0
},
"main()==>tideways_xhprof_disable": {
"ct": 1,
"wt": 2,
"cpu": 2,
"mu": 128,
"pmu": 0
}
}
--- noopcache 2018-09-18 14:48:18.628123276 +0200
+++ opcache 2018-09-18 14:48:26.624002320 +0200
@@ -1,79 +1,72 @@
Finding entry points
Branch analysis from position: 0
-Jump found. (Code = 42) Position 1 = 16
-Branch analysis from position: 16
-Jump found. (Code = 44) Position 1 = 18, Position 2 = 12
-Branch analysis from position: 18
-Jump found. (Code = 42) Position 1 = 36
-Branch analysis from position: 36
-Jump found. (Code = 44) Position 1 = 38, Position 2 = 32
-Branch analysis from position: 38
-Jump found. (Code = 62) Position 1 = -2
-Branch analysis from position: 32
-Jump found. (Code = 44) Position 1 = 38, Position 2 = 32
-Branch analysis from position: 38
-Branch analysis from position: 32
-Branch analysis from position: 12
-Jump found. (Code = 44) Position 1 = 18, Position 2 = 12
-Branch analysis from position: 18
+Jump found. (Code = 42) Position 1 = 12
Branch analysis from position: 12
+Jump found. (Code = 44) Position 1 = 14, Position 2 = 11
+Branch analysis from position: 14
+Jump found. (Code = 42) Position 1 = 29
+Branch analysis from position: 29
+Jump found. (Code = 44) Position 1 = 31, Position 2 = 28
+Branch analysis from position: 31
+Jump found. (Code = 62) Position 1 = -2
+Branch analysis from position: 28
+Jump found. (Code = 44) Position 1 = 31, Position 2 = 28
+Branch analysis from position: 31
+Branch analysis from position: 28
+Branch analysis from position: 11
+Jump found. (Code = 44) Position 1 = 14, Position 2 = 11
+Branch analysis from position: 14
+Branch analysis from position: 11
filename: /home/florian/work/docteurklein/xhprof-analyze/example/overhead.php
function name: (null)
-number of ops: 51
+number of ops: 44
compiled vars: !0 = $num, !1 = $argv, !2 = $start, !3 = $i, !4 = $duration, !5 = $start_p, !6 = $duration_p, !7 = $data
line #* E I O op fetch ext return operands
-------------------------------------------------------------------------------------
3 0 E > FETCH_DIM_IS $8 !1, 1
1 COALESCE ~9 $8
2 QM_ASSIGN ~9 '1e6'
- 3 CAST 5 ~10 ~9
- 4 ASSIGN !0, ~10
- 6 5 NOP
- 9 6 INIT_FCALL 'microtime'
- 7 SEND_VAL <true>
- 8 DO_FCALL 0 $12
- 9 ASSIGN !2, $12
- 11 10 ASSIGN !3, 0
- 11 > JMP ->16
- 12 12 > INIT_FCALL 'noop'
- 13 DO_FCALL 0
- 11 14 POST_INC ~16 !3
- 15 FREE ~16
- 16 > IS_SMALLER ~17 !3, !0
- 17 > JMPNZ ~17, ->12
- 14 18 > INIT_FCALL 'microtime'
- 19 SEND_VAL <true>
- 20 DO_FCALL 0 $18
- 21 SUB ~19 $18, !2
- 22 ASSIGN !4, ~19
- 16 23 INIT_FCALL 'tideways_xhprof_enable'
- 24 SEND_VAL 7
- 25 DO_FCALL 0
- 18 26 INIT_FCALL 'microtime'
- 27 SEND_VAL <true>
- 28 DO_FCALL 0 $22
- 29 ASSIGN !5, $22
- 20 30 ASSIGN !3, 0
- 31 > JMP ->36
- 21 32 > INIT_FCALL 'noop'
- 33 DO_FCALL 0
- 20 34 POST_INC ~26 !3
- 35 FREE ~26
- 36 > IS_SMALLER ~27 !3, !0
- 37 > JMPNZ ~27, ->32
- 23 38 > INIT_FCALL 'microtime'
- 39 SEND_VAL <true>
- 40 DO_FCALL 0 $28
- 41 SUB ~29 $28, !5
- 42 ASSIGN !6, ~29
- 25 43 INIT_FCALL 'json_encode'
- 44 INIT_FCALL 'tideways_xhprof_disable'
- 45 DO_FCALL 0 $31
- 46 SEND_VAR $31
- 47 DO_FCALL 0 $32
- 48 ASSIGN !7, $32
- 33 49 ECHO !7
- 34 50 > RETURN 1
+ 3 CAST 5 ~8 ~9
+ 4 ASSIGN !0, ~8
+ 9 5 INIT_FCALL 'microtime'
+ 6 SEND_VAL <true>
+ 7 DO_FCALL 0 $8
+ 8 ASSIGN !2, $8
+ 11 9 ASSIGN !3, 0
+ 10 > JMP ->12
+ 11 > PRE_INC !3
+ 12 > IS_SMALLER ~8 !3, !0
+ 13 > JMPNZ ~8, ->11
+ 14 14 > INIT_FCALL 'microtime'
+ 15 SEND_VAL <true>
+ 16 DO_FCALL 0 $9
+ 17 SUB ~8 $9, !2
+ 18 ASSIGN !4, ~8
+ 16 19 INIT_FCALL 'tideways_xhprof_enable'
+ 20 SEND_VAL 7
+ 21 DO_FCALL 0
+ 18 22 INIT_FCALL 'microtime'
+ 23 SEND_VAL <true>
+ 24 DO_FCALL 0 $8
+ 25 ASSIGN !5, $8
+ 20 26 ASSIGN !3, 0
+ 27 > JMP ->29
+ 28 > PRE_INC !3
+ 29 > IS_SMALLER ~8 !3, !0
+ 30 > JMPNZ ~8, ->28
+ 23 31 > INIT_FCALL 'microtime'
+ 32 SEND_VAL <true>
+ 33 DO_FCALL 0 $9
+ 34 SUB ~8 $9, !5
+ 35 ASSIGN !6, ~8
+ 25 36 INIT_FCALL 'json_encode'
+ 37 INIT_FCALL 'tideways_xhprof_disable'
+ 38 DO_FCALL 0 $8
+ 39 SEND_VAR $8
+ 40 DO_FCALL 0 $8
+ 41 ASSIGN !7, $8
+ 33 42 ECHO !7
+ 34 43 > RETURN 1
Function noop:
Finding entry points
% php -d zend_extension=opcache -d opcache.enable_cli=1 -n -d extension=$HOME/work/tideways/php-xhprof-extension/modules/tideways_xhprof.so -f example/overhead.php 1e6
iterations: 1000000
starting raw at: 1537275406.170 s
starting profiling at: 1537275406.177 s
raw: 6654 µs
profiler: 5944 µs
total overhead: -710 µs (x0.89)
avg overhead: -0.001 µs
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment