1
|
|
|
<?php |
2
|
|
|
declare(strict_types=1); |
3
|
|
|
|
4
|
|
|
namespace Yiisoft\Profiler; |
5
|
|
|
|
6
|
|
|
use Psr\Log\LogLevel; |
7
|
|
|
use Psr\Log\LoggerInterface; |
8
|
|
|
|
9
|
|
|
/** |
10
|
|
|
* Profiler provides profiling support. It stores profiling messages in the memory and sends them to different targets |
11
|
|
|
* according to {@see targets}. |
12
|
|
|
* |
13
|
|
|
* For more details and usage information on Profiler, see the [guide article on profiling](guide:runtime-profiling) |
14
|
|
|
*/ |
15
|
|
|
class Profiler implements ProfilerInterface |
16
|
|
|
{ |
17
|
|
|
/** |
18
|
|
|
* @var bool whether to profiler is enabled. Defaults to true. |
19
|
|
|
* You may use this field to disable writing of the profiling messages and thus save the memory usage. |
20
|
|
|
*/ |
21
|
|
|
private bool $enabled = true; |
22
|
|
|
|
23
|
|
|
/** |
24
|
|
|
* @var array[] complete profiling messages. |
25
|
|
|
* Each message has a following keys: |
26
|
|
|
* |
27
|
|
|
* - token: string, profiling token. |
28
|
|
|
* - category: string, message category. |
29
|
|
|
* - nestedLevel: int, profiling message nested level. |
30
|
|
|
* - beginTime: float, profiling begin timestamp obtained by microtime(true). |
31
|
|
|
* - endTime: float, profiling end timestamp obtained by microtime(true). |
32
|
|
|
* - duration: float, profiling block duration in milliseconds. |
33
|
|
|
* - beginMemory: int, memory usage at the beginning of profile block in bytes, obtained by `memory_get_usage()`. |
34
|
|
|
* - endMemory: int, memory usage at the end of profile block in bytes, obtained by `memory_get_usage()`. |
35
|
|
|
* - memoryDiff: int, a diff between 'endMemory' and 'beginMemory'. |
36
|
|
|
*/ |
37
|
|
|
private array $messages = []; |
38
|
|
|
|
39
|
|
|
/** |
40
|
|
|
* @var LoggerInterface logger to be used for message export. |
41
|
|
|
*/ |
42
|
|
|
private LoggerInterface $logger; |
43
|
|
|
|
44
|
|
|
/** |
45
|
|
|
* @var array pending profiling messages, e.g. the ones which have begun but not ended yet. |
46
|
|
|
*/ |
47
|
|
|
private array $pendingMessages = []; |
48
|
|
|
|
49
|
|
|
/** |
50
|
|
|
* @var int current profiling messages nested level. |
51
|
|
|
*/ |
52
|
|
|
private int $nestedLevel = 0; |
53
|
|
|
|
54
|
|
|
/** |
55
|
|
|
* @var array|Target[] the profiling targets. Each array element represents a single {@see Target|profiling target} |
56
|
|
|
* instance or the configuration for creating the profiling target instance. |
57
|
|
|
*/ |
58
|
|
|
private array $targets = []; |
59
|
|
|
|
60
|
|
|
/** |
61
|
|
|
* @var bool whether {@see targets} have been initialized, e.g. ensured to be objects. |
62
|
|
|
*/ |
63
|
|
|
private bool $isTargetsInitialized = false; |
64
|
|
|
|
65
|
|
|
|
66
|
|
|
/** |
67
|
|
|
* Initializes the profiler by registering {@see flush()} as a shutdown function. |
68
|
|
|
*/ |
69
|
4 |
|
public function __construct(LoggerInterface $logger) |
70
|
|
|
{ |
71
|
4 |
|
$this->logger = $logger; |
72
|
4 |
|
register_shutdown_function([$this, 'flush']); |
73
|
|
|
} |
74
|
|
|
|
75
|
|
|
/** |
76
|
|
|
* @return boolean the profile enabled. |
77
|
|
|
* |
78
|
|
|
* {@see enabled} |
79
|
|
|
*/ |
80
|
|
|
public function getEnabled(): bool |
81
|
|
|
{ |
82
|
|
|
return $this->enabled; |
83
|
|
|
} |
84
|
|
|
|
85
|
|
|
/** |
86
|
|
|
* @return array the messages profiler. |
87
|
|
|
*/ |
88
|
3 |
|
public function getMessages(): array |
89
|
|
|
{ |
90
|
3 |
|
return $this->messages; |
91
|
|
|
} |
92
|
|
|
|
93
|
|
|
/** |
94
|
|
|
* @return Target[] the profiling targets. Each array element represents a single {@see Target|profiling target} |
95
|
|
|
* instance. |
96
|
|
|
*/ |
97
|
2 |
|
public function getTargets(): array |
98
|
|
|
{ |
99
|
2 |
|
if (!$this->isTargetsInitialized) { |
100
|
2 |
|
foreach ($this->targets as $name => $target) { |
101
|
2 |
|
if (!$target instanceof Target) { |
102
|
1 |
|
$this->targets[$name] = new $target['__class']($target['logger'], $target['level']); |
103
|
|
|
} |
104
|
|
|
} |
105
|
2 |
|
$this->isTargetsInitialized = true; |
106
|
|
|
} |
107
|
|
|
|
108
|
2 |
|
return $this->targets; |
109
|
|
|
} |
110
|
|
|
|
111
|
|
|
/** |
112
|
|
|
* Set the profiler enabled or disabled. |
113
|
|
|
* |
114
|
|
|
* @param boolean $value |
115
|
|
|
* |
116
|
|
|
* @return void |
117
|
|
|
* |
118
|
|
|
* {@see enabled} |
119
|
|
|
*/ |
120
|
1 |
|
public function setEnabled(bool $value): void |
121
|
|
|
{ |
122
|
1 |
|
$this->enabled = $value; |
123
|
|
|
} |
124
|
|
|
|
125
|
|
|
/** |
126
|
|
|
* Set messages profiler. |
127
|
|
|
* |
128
|
|
|
* @param array $value |
129
|
|
|
* |
130
|
|
|
* @return void |
131
|
|
|
* |
132
|
|
|
* {@see messages} |
133
|
|
|
*/ |
134
|
|
|
public function setMessages(array $value): void |
135
|
|
|
{ |
136
|
|
|
$this->messages = $value; |
137
|
|
|
|
138
|
|
|
$this->dispatch($this->messages); |
139
|
|
|
} |
140
|
|
|
|
141
|
|
|
/** |
142
|
|
|
* @param array|Target[] $targets the profiling targets. Each array element represents a single |
143
|
|
|
* {@see Target|profiling target} instance or the configuration for creating the profiling target instance. |
144
|
|
|
*/ |
145
|
1 |
|
public function setTargets(array $targets): void |
146
|
|
|
{ |
147
|
1 |
|
$this->targets = $targets; |
148
|
1 |
|
$this->isTargetsInitialized = false; |
149
|
|
|
} |
150
|
|
|
|
151
|
|
|
/** |
152
|
|
|
* Adds extra target to {@see targets}. |
153
|
|
|
* |
154
|
|
|
* @param Target|array $target the log target instance or its DI compatible configuration. |
155
|
|
|
* @param string|null $name array key to be used to store target, if `null` is given target will be append |
156
|
|
|
* to the end of the array by natural integer key. |
157
|
|
|
*/ |
158
|
2 |
|
public function addTarget($target, ?string $name = null): void |
159
|
|
|
{ |
160
|
2 |
|
if (!$target instanceof Target) { |
161
|
|
|
$this->isTargetsInitialized = false; |
162
|
|
|
} |
163
|
|
|
|
164
|
2 |
|
if ($name === null) { |
165
|
2 |
|
$this->targets[] = $target; |
166
|
|
|
} else { |
167
|
1 |
|
$this->targets[$name] = $target; |
168
|
|
|
} |
169
|
|
|
} |
170
|
|
|
|
171
|
|
|
/** |
172
|
|
|
* {@inheritdoc} |
173
|
|
|
*/ |
174
|
4 |
|
public function begin(string $token, array $context = []): void |
175
|
|
|
{ |
176
|
4 |
|
if (!$this->enabled) { |
177
|
1 |
|
return; |
178
|
|
|
} |
179
|
|
|
|
180
|
4 |
|
$category = isset($context['category']) ?: 'application'; |
181
|
|
|
|
182
|
4 |
|
$message = array_merge($context, [ |
183
|
4 |
|
'token' => $token, |
184
|
4 |
|
'category' => $category, |
185
|
4 |
|
'nestedLevel' => $this->nestedLevel, |
186
|
4 |
|
'beginTime' => microtime(true), |
187
|
4 |
|
'beginMemory' => memory_get_usage(), |
188
|
|
|
]); |
189
|
|
|
|
190
|
4 |
|
$this->pendingMessages[$category][$token][] = $message; |
191
|
4 |
|
$this->nestedLevel++; |
192
|
|
|
} |
193
|
|
|
|
194
|
|
|
/** |
195
|
|
|
* {@inheritdoc} |
196
|
|
|
*/ |
197
|
4 |
|
public function end(string $token, array $context = []): void |
198
|
|
|
{ |
199
|
4 |
|
if (!$this->enabled) { |
200
|
1 |
|
return; |
201
|
|
|
} |
202
|
|
|
|
203
|
4 |
|
$category = isset($context['category']) ?: 'application'; |
204
|
|
|
|
205
|
4 |
|
if (empty($this->pendingMessages[$category][$token])) { |
206
|
|
|
throw new \InvalidArgumentException( |
207
|
|
|
'Unexpected ' . get_called_class() . |
208
|
|
|
'::end() call for category "' . |
209
|
|
|
$category . |
|
|
|
|
210
|
|
|
'" token "' . |
211
|
|
|
$token . '". A matching begin() is not found.' |
212
|
|
|
); |
213
|
|
|
} |
214
|
|
|
|
215
|
4 |
|
$message = array_pop($this->pendingMessages[$category][$token]); |
216
|
4 |
|
if (empty($this->pendingMessages[$category][$token])) { |
217
|
4 |
|
unset($this->pendingMessages[$category][$token]); |
218
|
|
|
|
219
|
4 |
|
if (empty($this->pendingMessages[$category])) { |
220
|
4 |
|
unset($this->pendingMessages[$category]); |
221
|
|
|
} |
222
|
|
|
} |
223
|
|
|
|
224
|
4 |
|
$message = array_merge( |
225
|
4 |
|
$message, |
226
|
|
|
$context, |
227
|
|
|
[ |
228
|
4 |
|
'endTime' => microtime(true), |
229
|
4 |
|
'endMemory' => memory_get_usage(), |
230
|
|
|
] |
231
|
|
|
); |
232
|
|
|
|
233
|
4 |
|
$message['duration'] = $message['endTime'] - $message['beginTime']; |
234
|
4 |
|
$message['memoryDiff'] = $message['endMemory'] - $message['beginMemory']; |
235
|
|
|
|
236
|
4 |
|
$this->messages[] = $message; |
237
|
4 |
|
$this->nestedLevel--; |
238
|
|
|
} |
239
|
|
|
|
240
|
|
|
/** |
241
|
|
|
* {@inheritdoc} |
242
|
|
|
*/ |
243
|
2 |
|
public function flush(): void |
244
|
|
|
{ |
245
|
2 |
|
foreach ($this->pendingMessages as $category => $categoryMessages) { |
246
|
|
|
foreach ($categoryMessages as $token => $messages) { |
247
|
|
|
if (!empty($messages)) { |
248
|
|
|
$this->logger->log( |
249
|
|
|
LogLevel::WARNING, |
250
|
|
|
'Unclosed profiling entry detected: category "' . $category . '" token "' . $token . '"' . ' ' . |
251
|
|
|
__METHOD__ |
252
|
|
|
); |
253
|
|
|
} |
254
|
|
|
} |
255
|
|
|
} |
256
|
|
|
|
257
|
2 |
|
$this->pendingMessages = []; |
258
|
2 |
|
$this->nestedLevel = 0; |
259
|
|
|
|
260
|
2 |
|
if (empty($this->messages)) { |
261
|
|
|
return; |
262
|
|
|
} |
263
|
|
|
|
264
|
2 |
|
$messages = $this->messages; |
265
|
|
|
|
266
|
|
|
// new messages could appear while the existing ones are being handled by targets |
267
|
2 |
|
$this->messages = []; |
268
|
|
|
|
269
|
2 |
|
$this->dispatch($messages); |
270
|
|
|
} |
271
|
|
|
|
272
|
|
|
/** |
273
|
|
|
* Dispatches the profiling messages to {@see targets}. |
274
|
|
|
* |
275
|
|
|
* @param array $messages the profiling messages. |
276
|
|
|
*/ |
277
|
1 |
|
protected function dispatch(array $messages): void |
278
|
|
|
{ |
279
|
1 |
|
foreach ($this->getTargets() as $target) { |
280
|
1 |
|
$target->collect($messages); |
281
|
|
|
} |
282
|
|
|
} |
283
|
|
|
} |
284
|
|
|
|