Profiling your PHP Application

So, you've been through and changed all your double quotes to single quotes but your application still isn't running at the speed of light. What's going on?

Making an application scale is generally seen as something that only the most magical of developers can do, but it's easy once you have the correct tools. Fortunately for us, these tools are freely available online!

In this talk, we'll take a look at a few options that we have available to work out what our application is actually doing, help identify bottlenecks and fix them so that we can move on to the more important part of the project: delivering features.

Transcript

1. Profiling PHP
   Michael Heap (@mheap)
   Developer at DataSift
   Presented at FOSDEM 2016
   

   View Slide

2. Me!
   I’m Michael
   I’m @mheap
   Developer at DataSift
   

   View Slide

3. Disclaimer
   

   View Slide

4. Profiling PHP
   

   View Slide

5. We Won't Cover
   Frontend optimisation
   Database queries
   TCP Negotiation
   

   View Slide

6. We Will Cover
   Quick wins
   Naive profiling
   XHProf
   XHGUI
   Other considerations
   

   View Slide

7. Quick Wins
   Things to do before you start profiling
   

   View Slide

8. $ php --go-faster
   

   View Slide

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

   View Slide

10. Async Workers
    Gearman
    Beanstalkd
    RabbitMQ
    ZeroMQ
    

    View Slide

11. Setting the scene
    

    View Slide

12. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    

    View Slide

13. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”, “interaction.author.name”]
    

    View Slide

14. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    

    View Slide

15. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    

    View Slide

16. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    

    View Slide

17. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    

    View Slide

18. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    

    View Slide

19. [“interaction.content”]
    {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    

    View Slide

20. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”]
    

    View Slide

21. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”]
    

    View Slide

22. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”]
    

    View Slide

23. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”]
    

    View Slide

24. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”]
    

    View Slide

25. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”, “interaction.author.name”]
    

    View Slide

26. Getting Started
    

    View Slide

27. $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);
    

    View Slide

28. $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);
    

    View Slide

29. $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);
    

    View Slide

30. $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);
    

    View Slide

31. $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);
    

    View Slide

32. 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
    

    View Slide

33. $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);
    

    View Slide

34. $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);
    

    View Slide

35. 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)
    );
    }
    

    View Slide

36. Run Times
    Without Cache: 11.717740058899
    With Cache: 8.7964880466461
    

    View Slide

37. Guessing
    

    View Slide

38. XHProf
    sudo pecl install xhprof-0.9.4
    extension=xhprof.so
    /usr/share/php/xhprof_lib
    

    View Slide

39. xhprof_enable(
    XHPROF_FLAGS_CPU +
    XHPROF_FLAGS_MEMORY
    )
    

    View Slide

40. $data = xhprof_disable();
    print_r($data);
    

    View Slide

41. [main()==>json_decode] => Array
    (
    [ct] => 50001
    [wt] => 4379326
    [cpu] => 4710383
    [mu] => 807834192
    [pmu] => 807572808
    )
    

    View Slide

42. 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");
    

    View Slide

43. No Cache
    

    View Slide

44. 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
    

    View Slide

45. 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
    

    View Slide

46. No Cache
    

    View Slide

47. No Cache
    

    View Slide

48. No Cache
    

    View Slide

49. No Cache
    Cache
    

    View Slide

50. Back to the task
    

    View Slide

51. {
    “interaction”: {
    “content": "Hello World”,
    ”author”: {
    “name”: ”Michael"
    }
    }
    }
    [“interaction.content”, “interaction.author.name”]
    

    View Slide

52. Version 1
    

    View Slide

53. 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;
    }
    

    View Slide

54. 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;
    }
    

    View Slide

55. 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;
    }
    

    View Slide

56. 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;
    }
    

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

60. 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
    

    View Slide

61. 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;
    }
    

    View Slide

62. View Slide

63. View Slide

64. Version 2
    

    View Slide

65. 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;
    }
    

    View Slide

66. 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;
    }
    

    View Slide

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

    View Slide

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

    View Slide

69. 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
    

    View Slide

70. View Slide

71. View Slide

72. Version 2.5
    

    View Slide

73. 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;
    }
    

    View Slide

74. 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
    

    View Slide

75. Version 3
    

    View Slide

76. 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;
    }
    

    View Slide

77. 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;
    }
    

    View Slide

78. 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
    

    View Slide

79. 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
    

    View Slide

80. 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
    

    View Slide

81. Version 4
    

    View Slide

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

    View Slide

83. 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
    

    View Slide

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

    View Slide

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

    View Slide

86. The UI
    

    View Slide

87. View Slide

88. View Slide

89. View Slide

90. View Slide

91. XHGui
    

    View Slide

92. View Slide

93. View Slide

94. View Slide

95. View Slide

96. blackfire.io
    

    View Slide

97. View Slide

98. View Slide

99. View Slide

100. View Slide

101. View Slide

102. View Slide

103. Other Tools
     XDebug/Cachegrind
     tideways.io
     New Relic
     catchy.io
     PHP Bench
     

     View Slide

104. Optimisation
     

     View Slide

105. Caching
     The fastest code is code that doesn't run
     

     View Slide

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

     View Slide

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

     View Slide

108. Logging
     Work out which code paths are popular
     Optimise them
     

     View Slide

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

     View Slide

110. Considerations
     Cache stampedes
     Circuit breakers
     

     View Slide

111. Process
     Measure
     Refactor
     Measure again
     Without measurements, you're just guessing
     

     View Slide

112. Is it worth it?
     

     View Slide

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

     View Slide