1
|
|
|
<?php |
2
|
|
|
namespace Elgg; |
3
|
|
|
use Elgg\Project\Paths; |
4
|
|
|
|
5
|
|
|
/** |
6
|
|
|
* Analyzes duration of functions, queries, and processes |
7
|
|
|
* |
8
|
|
|
* @access private |
9
|
|
|
*/ |
10
|
|
|
class Profiler { |
11
|
|
|
|
12
|
|
|
public $percentage_format = "%01.2f"; |
13
|
|
|
public $duration_format = "%01.6f"; |
14
|
|
|
public $minimum_percentage = 0.2; |
15
|
|
|
|
16
|
|
|
/** |
17
|
|
|
* @var float Total time |
18
|
|
|
*/ |
19
|
|
|
private $total; |
20
|
|
|
|
21
|
|
|
/** |
22
|
|
|
* Return a tree of time periods from a Timer |
23
|
|
|
* |
24
|
|
|
* @param Timer $timer Timer object |
25
|
|
|
* @return array |
26
|
|
|
*/ |
27
|
|
|
public function buildTree(Timer $timer) { |
28
|
|
|
$times = $timer->getTimes(); |
29
|
|
|
|
30
|
|
|
if (!isset($times[':end'])) { |
31
|
|
|
$times[':end'] = microtime(); |
32
|
|
|
} |
33
|
|
|
|
34
|
|
|
$begin = $this->findBeginTime($times); |
35
|
|
|
$end = $this->findEndTime($times); |
36
|
|
|
$this->total = $this->diffMicrotime($begin, $end); |
|
|
|
|
37
|
|
|
|
38
|
|
|
return $this->analyzePeriod('', $times); |
|
|
|
|
39
|
|
|
} |
40
|
|
|
|
41
|
|
|
/** |
42
|
|
|
* Turn the tree of times into a sorted list |
43
|
|
|
* |
44
|
|
|
* @param array $list Output list of times to populate |
45
|
|
|
* @param array $tree Result of buildTree() |
46
|
|
|
* @param string $prefix Prefix of period string. Leave empty. |
47
|
|
|
* @return void |
48
|
|
|
*/ |
49
|
|
|
public function flattenTree(array &$list = [], array $tree = [], $prefix = '') { |
50
|
|
|
$is_root = empty($list); |
51
|
|
|
|
52
|
|
|
if (isset($tree['periods'])) { |
53
|
|
|
foreach ($tree['periods'] as $period) { |
54
|
|
|
$this->flattenTree($list, $period, "{$prefix} {$period['name']}"); |
55
|
|
|
} |
56
|
|
|
unset($tree['periods']); |
57
|
|
|
} |
58
|
|
|
$tree['name'] = trim($prefix); |
59
|
|
|
$list[] = $tree; |
60
|
|
|
|
61
|
|
|
if ($is_root) { |
62
|
|
|
usort($list, function ($a, $b) { |
63
|
|
|
if ($a['duration'] == $b['duration']) { |
64
|
|
|
return 0; |
65
|
|
|
} |
66
|
|
|
return ($a['duration'] > $b['duration']) ? -1 : 1; |
67
|
|
|
}); |
68
|
|
|
} |
69
|
|
|
} |
70
|
|
|
|
71
|
|
|
/** |
72
|
|
|
* Nicely format the elapsed time values |
73
|
|
|
* |
74
|
|
|
* @param array $tree Result of buildTree() |
75
|
|
|
* @return array |
76
|
|
|
*/ |
77
|
|
|
public function formatTree(array $tree) { |
78
|
|
|
$tree['duration'] = sprintf($this->duration_format, $tree['duration']); |
79
|
|
|
if (isset($tree['percentage'])) { |
80
|
|
|
$tree['percentage'] = sprintf($this->percentage_format, $tree['percentage']); |
81
|
|
|
} |
82
|
|
|
if (isset($tree['periods'])) { |
83
|
|
|
$tree['periods'] = array_map([$this, 'formatTree'], $tree['periods']); |
84
|
|
|
} |
85
|
|
|
return $tree; |
86
|
|
|
} |
87
|
|
|
|
88
|
|
|
/** |
89
|
|
|
* Append a SCRIPT element to the page output |
90
|
|
|
* |
91
|
|
|
* @param string $hook "output" |
92
|
|
|
* @param string $type "page" |
93
|
|
|
* @param string $html Full page HTML |
94
|
|
|
* @param array $params Hook params |
95
|
|
|
* |
96
|
|
|
* @return string |
97
|
|
|
*/ |
98
|
|
|
public static function handlePageOutput($hook, $type, $html, $params) { |
|
|
|
|
99
|
|
|
$profiler = new self(); |
100
|
|
|
$min_percentage = _elgg_config()->profiling_minimum_percentage; |
101
|
|
|
if ($min_percentage !== null) { |
102
|
|
|
$profiler->minimum_percentage = $min_percentage; |
103
|
|
|
} |
104
|
|
|
|
105
|
|
|
$tree = $profiler->buildTree(_elgg_services()->timer); |
106
|
|
|
$tree = $profiler->formatTree($tree); |
107
|
|
|
$data['tree'] = $tree; |
|
|
|
|
108
|
|
|
$data['total'] = $tree['duration'] . " seconds"; |
109
|
|
|
|
110
|
|
|
$list = []; |
111
|
|
|
$profiler->flattenTree($list, $tree); |
112
|
|
|
|
113
|
|
|
$root = Paths::project(); |
114
|
|
|
$list = array_map(function ($period) use ($root) { |
115
|
|
|
$period['name'] = str_replace("Closure $root", "Closure ", $period['name']); |
116
|
|
|
return "{$period['percentage']}% ({$period['duration']}) {$period['name']}"; |
117
|
|
|
}, $list); |
118
|
|
|
|
119
|
|
|
$data['list'] = $list; |
120
|
|
|
|
121
|
|
|
$html .= "<script>console.log(" . json_encode($data) . ");</script>"; |
122
|
|
|
|
123
|
|
|
return $html; |
124
|
|
|
} |
125
|
|
|
|
126
|
|
|
/** |
127
|
|
|
* Analyze a time period |
128
|
|
|
* |
129
|
|
|
* @param string $name Period name |
130
|
|
|
* @param array $times Times |
131
|
|
|
* |
132
|
|
|
* @return array|bool False if missing begin/end time |
133
|
|
|
*/ |
134
|
|
|
private function analyzePeriod($name, array $times) { |
135
|
|
|
$begin = $this->findBeginTime($times); |
136
|
|
|
$end = $this->findEndTime($times); |
137
|
|
|
if ($begin === false || $end === false) { |
138
|
|
|
return false; |
139
|
|
|
} |
140
|
|
|
unset($times[':begin'], $times[':end']); |
141
|
|
|
|
142
|
|
|
$total = $this->diffMicrotime($begin, $end); |
143
|
|
|
$ret = [ |
144
|
|
|
'name' => $name, |
145
|
|
|
'percentage' => 100, // may be overwritten by parent |
146
|
|
|
'duration' => $total, |
147
|
|
|
]; |
148
|
|
|
|
149
|
|
|
foreach ($times as $times_key => $period) { |
150
|
|
|
$period = $this->analyzePeriod($times_key, $period); |
151
|
|
|
if ($period === false) { |
152
|
|
|
continue; |
153
|
|
|
} |
154
|
|
|
$period['percentage'] = 100 * $period['duration'] / $this->total; |
155
|
|
|
if ($period['percentage'] < $this->minimum_percentage) { |
156
|
|
|
continue; |
157
|
|
|
} |
158
|
|
|
$ret['periods'][] = $period; |
159
|
|
|
} |
160
|
|
|
|
161
|
|
|
if (isset($ret['periods'])) { |
162
|
|
|
usort($ret['periods'], function ($a, $b) { |
163
|
|
|
if ($a['duration'] == $b['duration']) { |
164
|
|
|
return 0; |
165
|
|
|
} |
166
|
|
|
return ($a['duration'] > $b['duration']) ? -1 : 1; |
167
|
|
|
}); |
168
|
|
|
} |
169
|
|
|
|
170
|
|
|
return $ret; |
171
|
|
|
} |
172
|
|
|
|
173
|
|
|
/** |
174
|
|
|
* Get the microtime start time |
175
|
|
|
* |
176
|
|
|
* @param array $times Time periods |
177
|
|
|
* @return string|false |
178
|
|
|
*/ |
179
|
|
|
private function findBeginTime(array $times) { |
180
|
|
|
if (isset($times[':begin'])) { |
181
|
|
|
return $times[':begin']; |
182
|
|
|
} |
183
|
|
|
unset($times[':begin'], $times[':end']); |
184
|
|
|
$first = reset($times); |
185
|
|
|
if (is_array($first)) { |
186
|
|
|
return $this->findBeginTime($first); |
187
|
|
|
} |
188
|
|
|
return false; |
189
|
|
|
} |
190
|
|
|
|
191
|
|
|
/** |
192
|
|
|
* Get the microtime end time |
193
|
|
|
* |
194
|
|
|
* @param array $times Time periods |
195
|
|
|
* @return string|false |
196
|
|
|
*/ |
197
|
|
|
private function findEndTime(array $times) { |
198
|
|
|
if (isset($times[':end'])) { |
199
|
|
|
return $times[':end']; |
200
|
|
|
} |
201
|
|
|
unset($times[':begin'], $times[':end']); |
202
|
|
|
$last = end($times); |
203
|
|
|
if (is_array($last)) { |
204
|
|
|
return $this->findEndTime($last); |
205
|
|
|
} |
206
|
|
|
return false; |
207
|
|
|
} |
208
|
|
|
|
209
|
|
|
/** |
210
|
|
|
* Calculate a precise time difference. |
211
|
|
|
* |
212
|
|
|
* @param string $start result of microtime() |
213
|
|
|
* @param string $end result of microtime() |
214
|
|
|
* |
215
|
|
|
* @return float difference in seconds, calculated with minimum precision loss |
216
|
|
|
*/ |
217
|
|
|
private function diffMicrotime($start, $end) { |
218
|
|
|
list($start_usec, $start_sec) = explode(" ", $start); |
219
|
|
|
list($end_usec, $end_sec) = explode(" ", $end); |
220
|
|
|
$diff_sec = (int) $end_sec - (int) $start_sec; |
221
|
|
|
$diff_usec = (float) $end_usec - (float) $start_usec; |
222
|
|
|
return (float) $diff_sec + $diff_usec; |
223
|
|
|
} |
224
|
|
|
} |
225
|
|
|
|