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