Slide 1

Slide 1 text

Profiling PHP Michael Heap (@mheap) Developer at DataSift Presented at php|tek, May 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/17051

Slide 4

Slide 4 text

Disclaimer

Slide 5

Slide 5 text

Profiling PHP

Slide 6

Slide 6 text

We Won’t Cover Frontend optimisation Database queries TCP Negotiation

Slide 7

Slide 7 text

We Will Cover Quick wins Naive profiling XHProf XHGUI Other considerations

Slide 8

Slide 8 text

Quick Wins Things to do before you start profiling

Slide 9

Slide 9 text

$ php --go-faster

Slide 10

Slide 10 text

$ php --go-faster $ apt-get upgrade php $ yum upgrade php $ pacman -S php

Slide 11

Slide 11 text

Async Workers Gearman Beanstalkd RabbitMQ ZeroMQ

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)) { $keys = array_merge($keys, $this->generate($v, array_merge($parents, $newFields))); } else { $keys[] = implode(array_merge($parents ,$newFields), "."); } } return $keys; }

Slide 71

Slide 71 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 72

Slide 72 text

public function generateAll($interactions) { $all = []; foreach ($interactions as $i) { $all = array_merge($all, $this->generate($i)); } return array_filter(array_unique($all)); }

Slide 73

Slide 73 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 74

Slide 74 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 75

Slide 75 text

No content

Slide 76

Slide 76 text

No content

Slide 77

Slide 77 text

Version 2.5

Slide 78

Slide 78 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 79

Slide 79 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 80

Slide 80 text

Version 3

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_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 82

Slide 82 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 83

Slide 83 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 84

Slide 84 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 85

Slide 85 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 86

Slide 86 text

Version 4

Slide 87

Slide 87 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 88

Slide 88 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 89

Slide 89 text

$currentDepth = []; foreach($parents as $x){ $currentDepth[] = $x; } foreach($newFields as $x){ $currentDepth[] = $x; }

Slide 90

Slide 90 text

$xx = \gettype($v)[0]; if ($xx == 'a' || $xx == 'o') {

Slide 91

Slide 91 text

The UI

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

No content

Slide 96

Slide 96 text

XHGui

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

blackfire.io

Slide 102

Slide 102 text

No content

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

XDebug/Cachegrind tideways.io New Relic Zend Z-Ray PHP Bench Other Tools

Slide 109

Slide 109 text

Observer effect

Slide 110

Slide 110 text

Optimisation

Slide 111

Slide 111 text

Caching The fastest code is code that doesn't run

Slide 112

Slide 112 text

Should it run? The fastest code is code that doesn't run

Slide 113

Slide 113 text

Measuring Production Enable 1 in 1000 requests (XHProf) Blackfire production mode (untested)

Slide 114

Slide 114 text

Logging Work out which code paths are popular Optimise them

Slide 115

Slide 115 text

Used/available memory Response time Timeout Successful/failed requests Open socket count Bandwidth usage Track Everything

Slide 116

Slide 116 text

Considerations Cache stampedes Circuit breakers

Slide 117

Slide 117 text

Measure Refactor Measure again Process

Slide 118

Slide 118 text

“Without measurements, you’re just guessing”

Slide 119

Slide 119 text

Is it worth it?

Slide 120

Slide 120 text

Usually, no

Slide 121

Slide 121 text

Thanks! I’ve been @mheap, you’ve been awesome. Please leave feedback on Joind.in https://joind.in/17051