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