Slide 1
Slide 1 text
Profiling PHP
Michael Heap (@mheap)
Developer at DataSift
Presented at PHP South Coast, June 2016
Slide 2
Slide 2 text
Me!
I’m Michael
I’m @mheap
Developer at DataSift
Slide 3
Slide 3 text
@mheap
https://joind.in/18028
Slide 4
Slide 4 text
Disclaimer
Slide 5
Slide 5 text
Profiling PHP
Slide 6
Slide 6 text
Profiling Applications
Slide 7
Slide 7 text
We Won’t Cover
Frontend optimisation
Database queries
TCP Negotiation
Slide 8
Slide 8 text
We Will Cover
Quick wins
Naive profiling
XHProf
XHGUI
Other considerations
Slide 9
Slide 9 text
Quick Wins
Things to do before you start profiling
Slide 10
Slide 10 text
$ php --go-faster
Slide 11
Slide 11 text
$ php --go-faster
$ apt-get upgrade php
$ yum upgrade php
$ pacman -S php
Slide 12
Slide 12 text
Setting the scene
Slide 13
Slide 13 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
Slide 14
Slide 14 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”, “interaction.author.name”]
Slide 15
Slide 15 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
Slide 16
Slide 16 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
Slide 17
Slide 17 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
Slide 18
Slide 18 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
Slide 19
Slide 19 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
Slide 20
Slide 20 text
[“interaction.content”]
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
Slide 21
Slide 21 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”]
Slide 22
Slide 22 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”]
Slide 23
Slide 23 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”]
Slide 24
Slide 24 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”]
Slide 25
Slide 25 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”]
Slide 26
Slide 26 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”, “interaction.author.name”]
Slide 27
Slide 27 text
{
"interaction": {
"author": {
"id": 115193554,
"link": "http://hooliganstsar.tumblr.com/",
"username": "hooliganstsar"
},
"content": "irhinoceri:\nWhen people try to discount Padme’s love for Anakin they completely ignore the fact that she says “stop come back I love you” even after she realizes that he’s committed murder and that he has delusions of grandeur where they become co-dictators.\nSure, it’s a desperate, emotional plea and not a promise that everything will return to normal. Not saying that. What I am saying is that she still loved him and believed there was
good in him even after he destroyed the very republic that s...",
"created_at": "Thu, 26 May 2016 15:12:31 +0000",
"id": "1e6235444361a9808d6a8de10491c475",
"link": "http://hooliganstsar.tumblr.com/post/144958725235",
"media_type": "text",
"received_at": 1464275553.0978,
"schema": {
"version": 3
},
"subtype": "post",
"type": "tumblr"
},
"language": {
"tag": "en",
"tag_extended": "en",
"confidence": 99
},
"salience": {
"content": {
"entities": [{
"name": "Padme",
"type": "Person",
"label": "Person",
"sentiment": -8,
"evidence": 7,
"confident": 1,
"about": 1,
"themes": ["flawed human", "committed murder", "n’t problematic", "justifiably upset", "Dark Side Anakin", "bad meta", "unemotional level", "space feminist", "true reason", "sentient beings", "including children", "political views cause"]
}, {
"name": "Obi Wan",
"type": "Person",
"label": "Person",
"sentiment": 5,
"evidence": 6,
"confident": 1,
"about": 0,
"themes": ["loved Anakin", "Obikin shippers"]
}, {
"name": "“stop come back I love you”",
"type": "Quote",
"label": "Quote",
"sentiment": 6,
"evidence": 1,
"confident": 1,
"about": 0,
"themes": ["committed murder", "emotional plea"]
}, {
"name": "“well I can respect this woman only if she loves the political system more than the person.”",
"type": "Quote",
"label": "Quote",
"sentiment": 4,
"evidence": 1,
"confident": 1,
"about": 0,
"themes": ["political system", "problematic husband ffs", "flawed human", "n’t problematic"]
}, {
"name": "“space feminist”",
"type": "Quote",
"label": "Quote",
"sentiment": 0,
"evidence": 1,
"confident": 1,
"about": 0,
"themes": ["true reason", "bad meta", "unemotional level", "space feminist", "sentient beings", "including children"]
}, {
"name": "“more.”",
"type": "Quote",
"label": "Quote",
"sentiment": 0,
"evidence": 1,
"confident": 1,
"about": 0,
"themes": ["different motivations"]
}],
"sentiment": 0,
"topics": [{
"name": "Crime",
"hits": 0,
"score": 0.66876006126404,
"additional": "irhinoceri: When people try to discount Padme’s love for Anakin they completely ignore the fact that she says “stop come back I love you” even after she realizes that he’s committed murder and that he has delusions of grandeur where they become co-dictators. It’s not like the republic wasn’t problematic itself so basically you’re pitting a flawed human being against a flawed political
system and saying “well I can respect this woman only if she loves the political system more than the person.” T..."
}]
}
},
"tumblr": {
"action": "create",
"activity": "post",
"blog": {
"id": "115193554",
"is_group_blog": false,
"name": "hooliganstsar",
"url": "http://hooliganstsar.tumblr.com/"
},
"blog_name": "hooliganstsar",
"blogid": "115193554",
"body": "irhinoceri:\n\nWhen people try to discount Padme’s love for Anakin they completely ignore the fact that she says “stop come back I love you” even after she realizes that he’s committed murder and that he has delusions of grandeur where they become co-dictators.\nSure, it’s a desperate, emotional plea and not a promise that everything will return to normal. Not saying that. What I am saying is that she still loved him and believed there was
good in him even after he destroyed the very republic that ...",
"created_at": "Thu, 26 May 2016 15:12:31 +0000",
"format": "html",
"id": "000533c038212bbbfd64395be146f382",
"is_submission": false,
"note_count": 397,
"post": {
"id": "144958725235",
"url": "http://hooliganstsar.tumblr.com/post/144958725235"
},
"post_url": "http://hooliganstsar.tumblr.com/post/144958725235",
"postid": "144958725235",
"reblogged": {
"parent": {
"blogid": "44626114",
"id": "144958505451",
"name": "imaginal",
"url": "http://imaginal.tumblr.com/post/144958505451"
},
"root": {
"blogid": "23604722",
"id": "140021104712",
"name": "irhinoceri",
"url": "http://irhinoceri.tumblr.com/post/140021104712"
},
"source": {
"blogid": "115193554"
}
},
"short_url": "https://tmblr.co/ZgfWkr270Dfnp",
"slug": "irhinoceri-when-people-try-to-discount-padmes",
"source_title": "irhinoceri",
"source_url": "http://irhinoceri.tumblr.com/post/140021104712/when-people-try-to-discount-padmes-love-for",
"type": "text",
"url": "https://tmblr.co/ZgfWkr270Dfnp"
}
}
Slide 28
Slide 28 text
Time limited
Resource limited
Fixed amount of data
Slide 29
Slide 29 text
Test harness
Slide 30
Slide 30 text
Example data
Slide 31
Slide 31 text
$start = microtime(true);
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
$tmp = json_decode($line, true);
if ($tmp) { $data[] = $tmp; }
}
echo "Took: ". (microtime(true) - $start);
Slide 32
Slide 32 text
$start = microtime(true);
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
$tmp = json_decode($line, true);
if ($tmp) { $data[] = $tmp; }
}
echo "Took: ". (microtime(true) - $start);
Slide 33
Slide 33 text
$start = microtime(true);
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
$tmp = json_decode($line, true);
if ($tmp) { $data[] = $tmp; }
}
echo "Took: ". (microtime(true) - $start);
Slide 34
Slide 34 text
$start = microtime(true);
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
$tmp = json_decode($line, true);
if ($tmp) { $data[] = $tmp; }
}
echo "Took: ". (microtime(true) - $start);
Slide 35
Slide 35 text
$start = microtime(true);
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
$tmp = json_decode($line, true);
if ($tmp) { $data[] = $tmp; }
}
echo "Took: ". (microtime(true) - $start);
Slide 36
Slide 36 text
Run Times
50,000 items: 5.7440850734711
50,000 items: 5.8537809848785
50,000 items: 5.5094730854034
50,000 items: 5.8217489719391
50,000 items: 5.8287329673767
Slide 37
Slide 37 text
$start = microtime(true);
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
$tmp = json_decode($line, true);
if ($tmp) { $data[] = $tmp; }
}
echo "Took: ". (microtime(true) - $start);
Slide 38
Slide 38 text
$start = microtime(true);
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
$tmp = json_decode($line, true);
if ($tmp) { $data[] = $tmp; }
}
echo "Took: ". (microtime(true) - $start);
Slide 39
Slide 39 text
if (file_exists("./cache")){
$data = json_decode(
file_get_contents("./cache"), true
);
} else {
$input = file_get_contents('./small.json');
foreach (explode("\n", $input) as $line){
// Decode and add to array
}
file_put_contents("./cache",
json_encode($data)
);
}
Slide 40
Slide 40 text
Run Times
Without Cache: 11.717740058899
With Cache: 8.7964880466461
Slide 41
Slide 41 text
Guessing
Slide 42
Slide 42 text
XHProf
sudo pecl install xhprof-0.9.4
extension=xhprof.so
/usr/share/php/xhprof_lib
Slide 43
Slide 43 text
xhprof_enable(
XHPROF_FLAGS_CPU +
XHPROF_FLAGS_MEMORY
)
Slide 44
Slide 44 text
$data = xhprof_disable();
print_r($data);
Slide 45
Slide 45 text
[main()==>json_decode] => Array
(
[ct] => 50001
[wt] => 4379326
[cpu] => 4710383
[mu] => 807834192
[pmu] => 807572808
)
Slide 46
Slide 46 text
include_once '/usr/share/php/xhprof_lib/utils/
xhprof_lib.php';
include_once '/usr/share/php/xhprof_lib/utils/
xhprof_runs.php';
$runs = new XHProfRuns_Default();
$runs->save_run($xhprof_data, "michael");
Slide 47
Slide 47 text
No Cache
Slide 48
Slide 48 text
Total Incl. Wall Time (microsec): 12,638,896 microsecs
Total Incl. CPU (microsecs): 9,692,792 microsecs
Total Incl. MemUse (bytes): 929,483,336 bytes
Total Incl. PeakMemUse (bytes): 1,170,441,880 bytes
Number of Function Calls: 50,008
No Cache
Slide 49
Slide 49 text
Total Incl. Wall Time (microsec): 9,473,467 microsecs
Total Incl. CPU (microsecs): 7,010,122 microsecs
Total Incl. MemUse (bytes): 815,163,360 bytes
Total Incl. PeakMemUse (bytes): 935,510,968 bytes
Number of Function Calls: 5
Cache
Slide 50
Slide 50 text
No Cache
Slide 51
Slide 51 text
No Cache
Slide 52
Slide 52 text
No Cache
Slide 53
Slide 53 text
No Cache
Cache
Slide 54
Slide 54 text
Back to the task
Slide 55
Slide 55 text
{
“interaction”: {
“content": "Hello World”,
”author”: {
“name”: ”Michael"
}
}
}
[“interaction.content”, “interaction.author.name”]
Slide 56
Slide 56 text
Version 1
Slide 57
Slide 57 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
$keys = array_merge($keys, $this->generate($v,
array_merge($parents, $newFields)));
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 58
Slide 58 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
$keys = array_merge($keys, $this->generate($v,
array_merge($parents, $newFields)));
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 59
Slide 59 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
$keys = array_merge($keys, $this->generate($v,
array_merge($parents, $newFields)));
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 60
Slide 60 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
$keys = array_merge($keys, $this->generate($v,
array_merge($parents, $newFields)));
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 61
Slide 61 text
public function generateAll($interactions) {
$all = [];
foreach ($interactions as $i) {
$all = array_merge($all, $this->generate($i));
}
return array_filter(array_unique($all));
}
Slide 62
Slide 62 text
public function generateAll($interactions) {
$all = [];
foreach ($interactions as $i) {
$all = array_merge($all, $this->generate($i));
}
return array_filter(array_unique($all));
}
Slide 63
Slide 63 text
public function generateAll($interactions) {
$all = [];
foreach ($interactions as $i) {
$all = array_merge($all, $this->generate($i));
}
return array_filter(array_unique($all));
}
Slide 64
Slide 64 text
Total Incl. Wall Time (microsec): 8,046,823 microsecs
Total Incl. CPU (microsecs): 8,018,211 microsecs
Total Incl. MemUse (bytes): 19,617,760 bytes
Total Incl. PeakMemUse (bytes): 37,543,384 bytes
Number of Function Calls: 355,764
Slide 65
Slide 65 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
$keys = array_merge($keys, $this->generate($v,
array_merge($parents, $newFields)));
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 66
Slide 66 text
No content
Slide 67
Slide 67 text
No content
Slide 68
Slide 68 text
Version 2
Slide 69
Slide 69 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
$keys = array_merge($keys, $this->generate($v,
array_merge($parents, $newFields)));
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 70
Slide 70 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
foreach ($this->generate($v, array_merge($parents, $newFields)
as $val) { $keys[] = $val; }
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 71
Slide 71 text
public function generateAll($interactions) {
$all = [];
foreach ($interactions as $i) {
$all = array_merge($all, $this->generate($i));
}
return array_filter(array_unique($all));
}
Slide 72
Slide 72 text
public function generateAll($interactions) {
$all = [];
foreach ($interactions as $i) {
foreach ($this->generate($i) as $g){
$all[] = $g;
}
}
return array_filter(array_unique($all));
}
Slide 73
Slide 73 text
Total Incl. Wall Time (microsec): 3,617,157 microsecs
Total Incl. CPU (microsecs): 3,539,472 microsecs
Total Incl. MemUse (bytes): 20,135,232 bytes
Total Incl. PeakMemUse (bytes): 37,407,936 bytes
Number of Function Calls: 334,278
Slide 74
Slide 74 text
No content
Slide 75
Slide 75 text
No content
Slide 76
Slide 76 text
Version 2.5
Slide 77
Slide 77 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if ($v instanceof Traversable) {
foreach ($this->generate($v, array_merge($parents, $newFields)
as $val) { $keys[] = $val; }
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 78
Slide 78 text
Total Incl. Wall Time (microsec): 274,998 microsecs
Total Incl. CPU (microsecs): 221,910 microsecs
Total Incl. MemUse (bytes): 19,510,464 bytes
Total Incl. PeakMemUse (bytes): 22,173,048 bytes
Number of Function Calls: 10,922
Slide 79
Slide 79 text
Version 3
Slide 80
Slide 80 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (is_array($v) || is_object($v)) {
foreach ($this->generate($v, array_merge($parents, $newFields)
as $val) { $keys[] = $val; }
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 81
Slide 81 text
public function generate($interaction, $parents = []) {
$keys = [];
foreach ($interaction as $k => $v) {
$newFields = [];
if (!is_numeric($k)) {
$newFields[] = $k;
}
if (!is_scalar($v)) {
foreach ($this->generate($v, array_merge($parents, $newFields)
as $val) { $keys[] = $val; }
} else {
$keys[] = implode(array_merge($parents ,$newFields), ".");
}
}
return $keys;
}
Slide 82
Slide 82 text
Total Incl. Wall Time (microsec): 2,926,818 microsecs
Total Incl. CPU (microsecs): 2,857,804 microsecs
Total Incl. MemUse (bytes): 20,126,960 bytes
Total Incl. PeakMemUse (bytes): 37,362,384 bytes
Number of Function Calls: 284,214
Slide 83
Slide 83 text
Total Incl. Wall Time (microsec): 3,617,157 microsecs
Total Incl. CPU (microsecs): 3,539,472 microsecs
Total Incl. MemUse (bytes): 20,135,232 bytes
Total Incl. PeakMemUse (bytes): 37,407,936 bytes
Number of Function Calls: 334,278
Slide 84
Slide 84 text
Total Incl. Wall Time (microsec): 2,926,818 microsecs
Total Incl. CPU (microsecs): 2,857,804 microsecs
Total Incl. MemUse (bytes): 20,126,960 bytes
Total Incl. PeakMemUse (bytes): 37,362,384 bytes
Number of Function Calls: 284,214
Slide 85
Slide 85 text
Version 4
Slide 86
Slide 86 text
Total Incl. Wall Time (microsec): 8,046,823 microsecs
Total Incl. CPU (microsecs): 8,018,211 microsecs
Total Incl. MemUse (bytes): 19,617,760 bytes
Total Incl. PeakMemUse (bytes): 37,543,384 bytes
Number of Function Calls: 355,764
Slide 87
Slide 87 text
Total Incl. Wall Time (microsec): 1,274,903 microsecs
Total Incl. CPU (microsecs): 1,195,136 microsecs
Total Incl. MemUse (bytes): 20,086,232 bytes
Total Incl. PeakMemUse (bytes): 34,597,576 bytes
Number of Function Calls: 93,053
Slide 88
Slide 88 text
$currentDepth = [];
foreach($parents as $x){ $currentDepth[] = $x; }
foreach($newFields as $x){ $currentDepth[] = $x; }
Slide 89
Slide 89 text
$xx = \gettype($v)[0];
if ($xx == 'a' || $xx == 'o') {
Slide 90
Slide 90 text
XHProf UI
Slide 91
Slide 91 text
No content
Slide 92
Slide 92 text
No content
Slide 93
Slide 93 text
No content
Slide 94
Slide 94 text
No content
Slide 95
Slide 95 text
XHGui
Slide 96
Slide 96 text
No content
Slide 97
Slide 97 text
No content
Slide 98
Slide 98 text
No content
Slide 99
Slide 99 text
No content
Slide 100
Slide 100 text
No content
Slide 101
Slide 101 text
No content
Slide 102
Slide 102 text
blackfire.io
Slide 103
Slide 103 text
No content
Slide 104
Slide 104 text
No content
Slide 105
Slide 105 text
No content
Slide 106
Slide 106 text
No content
Slide 107
Slide 107 text
No content
Slide 108
Slide 108 text
No content
Slide 109
Slide 109 text
No content
Slide 110
Slide 110 text
No content
Slide 111
Slide 111 text
Production friendly
Slide 112
Slide 112 text
Read more
https://www.colinodell.com/blog/2015-11/
optimizing-league-commonmark-blackfire-io
Slide 113
Slide 113 text
XDebug/Cachegrind
tideways.io
New Relic
Zend Z-Ray
PHP Bench
Other Tools
Slide 114
Slide 114 text
Observer effect
Slide 115
Slide 115 text
Optimisation
Slide 116
Slide 116 text
Caching
The fastest code is code that doesn't run
Slide 117
Slide 117 text
Should it run?
The fastest code is code that doesn't run
Slide 118
Slide 118 text
Async Workers
Gearman
Beanstalkd
RabbitMQ
ZeroMQ
Slide 119
Slide 119 text
Logging
Work out which code paths are popular
Optimise them
Slide 120
Slide 120 text
Measuring Production
Enable 1 in 1000 requests with XHProf
Blackfire production mode (with header)
Slide 121
Slide 121 text
Used/available memory
Response time
Timeout
Successful/failed requests
Open socket count
Bandwidth usage
Track Everything
Slide 122
Slide 122 text
Profile Everything
Framework bootstrapping
Business logic
Unit tests
Slide 123
Slide 123 text
Measure
Refactor
Measure again
Process
Slide 124
Slide 124 text
“Without measurements,
you’re just guessing”
Slide 125
Slide 125 text
Is it worth it?
Slide 126
Slide 126 text
Usually, no
Slide 127
Slide 127 text
No content
Slide 128
Slide 128 text
Thanks!
I’ve been @mheap, you’ve been awesome.
Please leave feedback on Joind.in
https://joind.in/18028