1
|
|
|
<?php |
2
|
|
|
|
3
|
|
|
namespace WikibaseQuality\ConstraintReport\ConstraintCheck\Helper; |
4
|
|
|
|
5
|
|
|
use Config; |
6
|
|
|
use IBufferingStatsdDataFactory; |
7
|
|
|
use Psr\Log\LoggerInterface; |
8
|
|
|
use Wikibase\DataModel\Entity\EntityId; |
9
|
|
|
use WikibaseQuality\ConstraintReport\Constraint; |
10
|
|
|
use WikibaseQuality\ConstraintReport\ConstraintCheck\Context\Context; |
11
|
|
|
use WikibaseQuality\ConstraintReport\ConstraintCheck\Result\CheckResult; |
12
|
|
|
|
13
|
|
|
/** |
14
|
|
|
* Helper class for tracking and logging messages. |
15
|
|
|
* |
16
|
|
|
* @author Lucas Werkmeister |
17
|
|
|
* @license GPL-2.0-or-later |
18
|
|
|
*/ |
19
|
|
|
class LoggingHelper { |
20
|
|
|
|
21
|
|
|
/** |
22
|
|
|
* @var IBufferingStatsdDataFactory |
23
|
|
|
*/ |
24
|
|
|
private $dataFactory; |
25
|
|
|
|
26
|
|
|
/** |
27
|
|
|
* @var LoggerInterface |
28
|
|
|
*/ |
29
|
|
|
private $logger; |
30
|
|
|
|
31
|
|
|
/** |
32
|
|
|
* @var float[] |
33
|
|
|
*/ |
34
|
|
|
private $constraintCheckDurationLimits; |
35
|
|
|
|
36
|
|
|
/** |
37
|
|
|
* @var float[] |
38
|
|
|
*/ |
39
|
|
|
private $constraintCheckOnEntityDurationLimits; |
40
|
|
|
|
41
|
|
|
/** |
42
|
|
|
* @param IBufferingStatsdDataFactory $dataFactory, |
|
|
|
|
43
|
|
|
* @param LoggerInterface $logger |
44
|
|
|
* @param Config $config |
45
|
|
|
*/ |
46
|
|
|
public function __construct( |
47
|
|
|
IBufferingStatsdDataFactory $dataFactory, |
48
|
|
|
LoggerInterface $logger, |
49
|
|
|
Config $config |
50
|
|
|
) { |
51
|
|
|
$this->dataFactory = $dataFactory; |
52
|
|
|
$this->logger = $logger; |
53
|
|
|
$this->constraintCheckDurationLimits = [ |
|
|
|
|
54
|
|
|
'info' => $config->get( 'WBQualityConstraintsCheckDurationInfoSeconds' ), |
55
|
|
|
'warning' => $config->get( 'WBQualityConstraintsCheckDurationWarningSeconds' ), |
56
|
|
|
]; |
57
|
|
|
$this->constraintCheckOnEntityDurationLimits = [ |
|
|
|
|
58
|
|
|
'info' => $config->get( 'WBQualityConstraintsCheckOnEntityDurationInfoSeconds' ), |
59
|
|
|
'warning' => $config->get( 'WBQualityConstraintsCheckOnEntityDurationWarningSeconds' ), |
60
|
|
|
]; |
61
|
|
|
} |
62
|
|
|
|
63
|
|
|
/** |
64
|
|
|
* Find the longest limit in $limits which the $durationSeconds exceeds, |
65
|
|
|
* and return it along with the associated log level. |
66
|
|
|
* |
67
|
|
|
* @param float $durationSeconds |
68
|
|
|
* @return array [ $limitSeconds, $logLevel ] |
69
|
|
|
*/ |
70
|
|
|
private function findLimit( $limits, $durationSeconds ) { |
71
|
|
|
$limitSeconds = null; |
72
|
|
|
$logLevel = null; |
73
|
|
|
|
74
|
|
|
foreach ( $limits as $level => $limit ) { |
75
|
|
|
if ( |
76
|
|
|
// duration exceeds this limit |
77
|
|
|
isset( $limit ) && $durationSeconds > $limit && |
78
|
|
|
// this limit is longer than previous longest limit |
79
|
|
|
( $limitSeconds === null || $limit > $limitSeconds ) |
80
|
|
|
) { |
81
|
|
|
$limitSeconds = $limit; |
82
|
|
|
$logLevel = $level; |
83
|
|
|
} |
84
|
|
|
} |
85
|
|
|
|
86
|
|
|
return [ $limitSeconds, $logLevel ]; |
87
|
|
|
} |
88
|
|
|
|
89
|
|
|
/** |
90
|
|
|
* Log a single constraint check. |
91
|
|
|
* The constraint check is tracked on the statsd data factory, |
92
|
|
|
* and also logged with the logger interface if it took longer than a certain time. |
93
|
|
|
* Multiple limits corresponding to different log levels can be specified in the configuration; |
94
|
|
|
* checks that exceed a higher limit are logged at a more severe level. |
95
|
|
|
* |
96
|
|
|
* @param Context $context |
97
|
|
|
* @param Constraint $constraint |
98
|
|
|
* @param CheckResult $result |
99
|
|
|
* @param string $constraintCheckerClass |
100
|
|
|
* @param float $durationSeconds |
101
|
|
|
* @param string $method Use __METHOD__. |
102
|
|
|
*/ |
103
|
|
|
public function logConstraintCheck( |
104
|
|
|
Context $context, |
105
|
|
|
Constraint $constraint, |
106
|
|
|
CheckResult $result, |
107
|
|
|
$constraintCheckerClass, |
108
|
|
|
$durationSeconds, |
109
|
|
|
$method |
110
|
|
|
) { |
111
|
|
|
$constraintCheckerClassShortName = substr( strrchr( $constraintCheckerClass, '\\' ), 1 ); |
112
|
|
|
$constraintTypeItemId = $constraint->getConstraintTypeItemId(); |
113
|
|
|
|
114
|
|
|
$this->dataFactory->timing( |
115
|
|
|
'wikibase.quality.constraints.check.timing.' . |
116
|
|
|
$constraintTypeItemId . '-' . |
117
|
|
|
$constraintCheckerClassShortName, |
118
|
|
|
$durationSeconds * 1000 |
119
|
|
|
); |
120
|
|
|
|
121
|
|
|
// find the longest limit (and associated log level) that the duration exceeds |
122
|
|
|
list( $limitSeconds, $logLevel ) = $this->findLimit( |
123
|
|
|
$this->constraintCheckDurationLimits, |
124
|
|
|
$durationSeconds |
125
|
|
|
); |
126
|
|
|
if ( $limitSeconds === null ) { |
127
|
|
|
return; |
128
|
|
|
} |
129
|
|
|
if ( $context->getType() !== Context::TYPE_STATEMENT ) { |
130
|
|
|
// TODO log less details but still log something |
131
|
|
|
return; |
132
|
|
|
} |
133
|
|
|
|
134
|
|
|
$resultMessage = $result->getMessage(); |
135
|
|
|
if ( $resultMessage !== null ) { |
136
|
|
|
$resultMessageKey = $resultMessage->getMessageKey(); |
137
|
|
|
} else { |
138
|
|
|
$resultMessageKey = null; |
139
|
|
|
} |
140
|
|
|
|
141
|
|
|
$this->logger->log( |
142
|
|
|
$logLevel, |
143
|
|
|
'Constraint check with {constraintCheckerClassShortName} ' . |
144
|
|
|
'took longer than {limitSeconds} second(s) ' . |
145
|
|
|
'(duration: {durationSeconds} seconds).', |
146
|
|
|
[ |
147
|
|
|
'method' => $method, |
148
|
|
|
'loggingMethod' => __METHOD__, |
149
|
|
|
'durationSeconds' => $durationSeconds, |
150
|
|
|
'limitSeconds' => $limitSeconds, |
151
|
|
|
'constraintId' => $constraint->getConstraintId(), |
152
|
|
|
'constraintPropertyId' => $constraint->getPropertyId()->getSerialization(), |
153
|
|
|
'constraintTypeItemId' => $constraintTypeItemId, |
154
|
|
|
'constraintParameters' => json_encode( $constraint->getConstraintParameters() ), |
155
|
|
|
'constraintCheckerClass' => $constraintCheckerClass, |
156
|
|
|
'constraintCheckerClassShortName' => $constraintCheckerClassShortName, |
157
|
|
|
'entityId' => $context->getEntity()->getId()->getSerialization(), |
158
|
|
|
'statementGuid' => $context->getSnakStatement()->getGuid(), |
159
|
|
|
'resultStatus' => $result->getStatus(), |
160
|
|
|
'resultParameters' => json_encode( $result->getParameters() ), |
161
|
|
|
'resultMessage' => $resultMessageKey, |
162
|
|
|
] |
163
|
|
|
); |
164
|
|
|
} |
165
|
|
|
|
166
|
|
|
/** |
167
|
|
|
* Log a full constraint check on an entity. |
168
|
|
|
* The constraint check is tracked on the statsd data factory, |
169
|
|
|
* and also logged with the logger interface if it took longer than a certain time. |
170
|
|
|
* Multiple limits corresponding to different log levels can be specified in the configuration; |
171
|
|
|
* checks that exceed a higher limit are logged at a more severe level. |
172
|
|
|
* |
173
|
|
|
* |
174
|
|
|
* @param EntityId $entityId |
175
|
|
|
* @param CheckResult[] $checkResults |
176
|
|
|
* @param float $durationSeconds |
177
|
|
|
*/ |
178
|
|
|
public function logConstraintCheckOnEntity( |
179
|
|
|
EntityId $entityId, |
180
|
|
|
array $checkResults, |
|
|
|
|
181
|
|
|
$durationSeconds, |
182
|
|
|
$method |
183
|
|
|
) { |
184
|
|
|
$this->dataFactory->timing( |
185
|
|
|
'wikibase.quality.constraints.check.entity.timing', |
186
|
|
|
$durationSeconds * 1000 |
187
|
|
|
); |
188
|
|
|
|
189
|
|
|
// find the longest limit (and associated log level) that the duration exceeds |
190
|
|
|
list( $limitSeconds, $logLevel ) = $this->findLimit( |
191
|
|
|
$this->constraintCheckOnEntityDurationLimits, |
192
|
|
|
$durationSeconds |
193
|
|
|
); |
194
|
|
|
if ( $limitSeconds === null ) { |
195
|
|
|
return; |
196
|
|
|
} |
197
|
|
|
|
198
|
|
|
$this->logger->log( |
199
|
|
|
$logLevel, |
200
|
|
|
'Full constraint check on {entityId} ' . |
201
|
|
|
'took longer than {limitSeconds} second(s) ' . |
202
|
|
|
'(duration: {durationSeconds} seconds).', |
203
|
|
|
[ |
204
|
|
|
'method' => $method, |
205
|
|
|
'loggingMethod' => __METHOD__, |
206
|
|
|
'durationSeconds' => $durationSeconds, |
207
|
|
|
'limitSeconds' => $limitSeconds, |
208
|
|
|
'entityId' => $entityId->getSerialization(), |
209
|
|
|
// $checkResults currently not logged |
210
|
|
|
] |
211
|
|
|
); |
212
|
|
|
} |
213
|
|
|
|
214
|
|
|
/** |
215
|
|
|
* Log a cache hit for a complete constraint check result for the given entity ID. |
216
|
|
|
* |
217
|
|
|
* @param EntityId $entityId |
218
|
|
|
*/ |
219
|
|
|
public function logCheckConstraintsCacheHit( EntityId $entityId ) { |
|
|
|
|
220
|
|
|
$this->dataFactory->increment( |
221
|
|
|
'wikibase.quality.constraints.cache.entity.hit' |
222
|
|
|
); |
223
|
|
|
} |
224
|
|
|
|
225
|
|
|
/** |
226
|
|
|
* Log cache misses for a complete constraint check result for the given entity IDs. |
227
|
|
|
* |
228
|
|
|
* @param EntityId[] $entityIds |
229
|
|
|
*/ |
230
|
|
|
public function logCheckConstraintsCacheMisses( array $entityIds ) { |
231
|
|
|
$this->dataFactory->updateCount( |
232
|
|
|
'wikibase.quality.constraints.cache.entity.miss', |
233
|
|
|
count( $entityIds ) |
234
|
|
|
); |
235
|
|
|
} |
236
|
|
|
|
237
|
|
|
/** |
238
|
|
|
* Log that the dependency metadata for a check result had an empty set of entity IDs. |
239
|
|
|
* This should never happen – at least the entity being checked should always be contained. |
240
|
|
|
*/ |
241
|
|
|
public function logEmptyDependencyMetadata() { |
242
|
|
|
$this->logger->log( |
243
|
|
|
'warning', |
244
|
|
|
'Dependency metadata for constraint check result had empty set of entity IDs.', |
245
|
|
|
[ |
246
|
|
|
'loggingMethod' => __METHOD__, |
247
|
|
|
// callers of this method don’t have much information to pass to us, |
248
|
|
|
// so for now we don’t log any other structured data |
249
|
|
|
// and hope that the request URL provides enough information |
250
|
|
|
] |
251
|
|
|
); |
252
|
|
|
} |
253
|
|
|
|
254
|
|
|
/** |
255
|
|
|
* Log that the dependency metadata for a check result has a very large set of entity IDs. |
256
|
|
|
* |
257
|
|
|
* @param EntityId[] $entityIds |
258
|
|
|
* @param int $maxRevisionIds |
259
|
|
|
*/ |
260
|
|
|
public function logHugeDependencyMetadata( array $entityIds, $maxRevisionIds ) { |
261
|
|
|
$this->logger->log( |
262
|
|
|
'warning', |
263
|
|
|
'Dependency metadata for constraint check result has huge set of entity IDs ' . |
264
|
|
|
'(count ' . count( $entityIds ) . ', limit ' . $maxRevisionIds . '); ' . |
265
|
|
|
'caching disabled for this check result.', |
266
|
|
|
[ |
267
|
|
|
'loggingMethod' => __METHOD__, |
268
|
|
|
'entityIds' => json_encode( |
269
|
|
|
array_map( |
270
|
|
|
function ( EntityId $entityId ) { |
271
|
|
|
return $entityId->getSerialization(); |
272
|
|
|
}, |
273
|
|
|
$entityIds |
274
|
|
|
) |
275
|
|
|
), |
276
|
|
|
'maxRevisionIds' => $maxRevisionIds, |
277
|
|
|
] |
278
|
|
|
); |
279
|
|
|
} |
280
|
|
|
|
281
|
|
|
} |
282
|
|
|
|
This check looks for PHPDoc comments describing methods or function parameters that do not exist on the corresponding method or function. It has, however, found a similar but not annotated parameter which might be a good fit.
Consider the following example. The parameter
$ireland
is not defined by the methodfinale(...)
.The most likely cause is that the parameter was changed, but the annotation was not.