Completed
Push — master ( 64b8b5...1ef719 )
by
unknown
06:56
created

logSparqlHelperTooManyRequestsRetryAfterInvalid()   A

Complexity

Conditions 1
Paths 1

Size

Total Lines 9

Duplication

Lines 0
Ratio 0 %

Importance

Changes 0
Metric Value
dl 0
loc 9
rs 9.9666
c 0
b 0
f 0
cc 1
nc 1
nop 1
1
<?php
2
3
namespace WikibaseQuality\ConstraintReport\ConstraintCheck\Helper;
4
5
use Config;
6
use IBufferingStatsdDataFactory;
7
use MWHttpRequest;
8
use Psr\Log\LoggerInterface;
9
use Wikibase\DataModel\Entity\EntityId;
10
use WikibaseQuality\ConstraintReport\Constraint;
11
use WikibaseQuality\ConstraintReport\ConstraintCheck\Context\Context;
12
use WikibaseQuality\ConstraintReport\ConstraintCheck\Result\CheckResult;
13
use Wikimedia\Timestamp\ConvertibleTimestamp;
14
15
/**
16
 * Helper class for tracking and logging messages.
17
 *
18
 * @author Lucas Werkmeister
19
 * @license GPL-2.0-or-later
20
 */
21
class LoggingHelper {
22
23
	/**
24
	 * @var IBufferingStatsdDataFactory
25
	 */
26
	private $dataFactory;
27
28
	/**
29
	 * @var LoggerInterface
30
	 */
31
	private $logger;
32
33
	/**
34
	 * @var float[]
35
	 */
36
	private $constraintCheckDurationLimits;
37
38
	/**
39
	 * @var float[]
40
	 */
41
	private $constraintCheckOnEntityDurationLimits;
42
43
	/**
44
	 * @param IBufferingStatsdDataFactory $dataFactory,
0 ignored issues
show
Documentation introduced by
There is no parameter named $dataFactory,. Did you maybe mean $dataFactory?

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 method finale(...).

/**
 * @param array $germany
 * @param array $ireland
 */
function finale($germany, $island) {
    return "2:1";
}

The most likely cause is that the parameter was changed, but the annotation was not.

Loading history...
45
	 * @param LoggerInterface $logger
46
	 * @param Config $config
47
	 */
48
	public function __construct(
49
		IBufferingStatsdDataFactory $dataFactory,
50
		LoggerInterface $logger,
51
		Config $config
52
	) {
53
		$this->dataFactory = $dataFactory;
54
		$this->logger = $logger;
55
		$this->constraintCheckDurationLimits = [
0 ignored issues
show
Documentation Bug introduced by
It seems like array('info' => $config-...rationWarningSeconds')) of type array<string,?,{"info":"?","warning":"?"}> is incompatible with the declared type array<integer,double> of property $constraintCheckDurationLimits.

Our type inference engine has found an assignment to a property that is incompatible with the declared type of that property.

Either this assignment is in error or the assigned type should be added to the documentation/type hint for that property..

Loading history...
56
			'info' => $config->get( 'WBQualityConstraintsCheckDurationInfoSeconds' ),
57
			'warning' => $config->get( 'WBQualityConstraintsCheckDurationWarningSeconds' ),
58
		];
59
		$this->constraintCheckOnEntityDurationLimits = [
0 ignored issues
show
Documentation Bug introduced by
It seems like array('info' => $config-...rationWarningSeconds')) of type array<string,?,{"info":"?","warning":"?"}> is incompatible with the declared type array<integer,double> of property $constraintCheckOnEntityDurationLimits.

Our type inference engine has found an assignment to a property that is incompatible with the declared type of that property.

Either this assignment is in error or the assigned type should be added to the documentation/type hint for that property..

Loading history...
60
			'info' => $config->get( 'WBQualityConstraintsCheckOnEntityDurationInfoSeconds' ),
61
			'warning' => $config->get( 'WBQualityConstraintsCheckOnEntityDurationWarningSeconds' ),
62
		];
63
	}
64
65
	/**
66
	 * Find the longest limit in $limits which the $durationSeconds exceeds,
67
	 * and return it along with the associated log level.
68
	 *
69
	 * @param float $durationSeconds
70
	 * @return array [ $limitSeconds, $logLevel ]
71
	 */
72
	private function findLimit( $limits, $durationSeconds ) {
73
		$limitSeconds = null;
74
		$logLevel = null;
75
76
		foreach ( $limits as $level => $limit ) {
77
			if (
78
				// duration exceeds this limit
79
				isset( $limit ) && $durationSeconds > $limit &&
80
				// this limit is longer than previous longest limit
81
				( $limitSeconds === null || $limit > $limitSeconds )
82
			) {
83
				$limitSeconds = $limit;
84
				$logLevel = $level;
85
			}
86
		}
87
88
		return [ $limitSeconds, $logLevel ];
89
	}
90
91
	/**
92
	 * Log a single constraint check.
93
	 * The constraint check is tracked on the statsd data factory,
94
	 * and also logged with the logger interface if it took longer than a certain time.
95
	 * Multiple limits corresponding to different log levels can be specified in the configuration;
96
	 * checks that exceed a higher limit are logged at a more severe level.
97
	 *
98
	 * @param Context $context
99
	 * @param Constraint $constraint
100
	 * @param CheckResult $result
101
	 * @param string $constraintCheckerClass
102
	 * @param float $durationSeconds
103
	 * @param string $method Use __METHOD__.
104
	 */
105
	public function logConstraintCheck(
106
		Context $context,
107
		Constraint $constraint,
108
		CheckResult $result,
109
		$constraintCheckerClass,
110
		$durationSeconds,
111
		$method
112
	) {
113
		$constraintCheckerClassShortName = substr( strrchr( $constraintCheckerClass, '\\' ), 1 );
114
		$constraintTypeItemId = $constraint->getConstraintTypeItemId();
115
116
		$this->dataFactory->timing(
117
			'wikibase.quality.constraints.check.timing.' .
118
				$constraintTypeItemId . '-' .
119
				$constraintCheckerClassShortName,
120
			$durationSeconds * 1000
121
		);
122
123
		// find the longest limit (and associated log level) that the duration exceeds
124
		list( $limitSeconds, $logLevel ) = $this->findLimit(
125
			$this->constraintCheckDurationLimits,
126
			$durationSeconds
127
		);
128
		if ( $limitSeconds === null ) {
129
			return;
130
		}
131
		if ( $context->getType() !== Context::TYPE_STATEMENT ) {
132
			// TODO log less details but still log something
133
			return;
134
		}
135
136
		$resultMessage = $result->getMessage();
137
		if ( $resultMessage !== null ) {
138
			$resultMessageKey = $resultMessage->getMessageKey();
139
		} else {
140
			$resultMessageKey = null;
141
		}
142
143
		$this->logger->log(
144
			$logLevel,
145
			'Constraint check with {constraintCheckerClassShortName} ' .
146
			'took longer than {limitSeconds} second(s) ' .
147
			'(duration: {durationSeconds} seconds).',
148
			[
149
				'method' => $method,
150
				'loggingMethod' => __METHOD__,
151
				'durationSeconds' => $durationSeconds,
152
				'limitSeconds' => $limitSeconds,
153
				'constraintId' => $constraint->getConstraintId(),
154
				'constraintPropertyId' => $constraint->getPropertyId()->getSerialization(),
155
				'constraintTypeItemId' => $constraintTypeItemId,
156
				'constraintParameters' => json_encode( $constraint->getConstraintParameters() ),
157
				'constraintCheckerClass' => $constraintCheckerClass,
158
				'constraintCheckerClassShortName' => $constraintCheckerClassShortName,
159
				'entityId' => $context->getEntity()->getId()->getSerialization(),
160
				'statementGuid' => $context->getSnakStatement()->getGuid(),
161
				'resultStatus' => $result->getStatus(),
162
				'resultParameters' => json_encode( $result->getParameters() ),
163
				'resultMessage' => $resultMessageKey,
164
			]
165
		);
166
	}
167
168
	/**
169
	 * Log a full constraint check on an entity.
170
	 * The constraint check is tracked on the statsd data factory,
171
	 * and also logged with the logger interface if it took longer than a certain time.
172
	 * Multiple limits corresponding to different log levels can be specified in the configuration;
173
	 * checks that exceed a higher limit are logged at a more severe level.
174
	 *
175
	 *
176
	 * @param EntityId $entityId
177
	 * @param CheckResult[] $checkResults
178
	 * @param float $durationSeconds
179
	 */
180
	public function logConstraintCheckOnEntity(
181
		EntityId $entityId,
182
		array $checkResults,
0 ignored issues
show
Unused Code introduced by
The parameter $checkResults is not used and could be removed.

This check looks from parameters that have been defined for a function or method, but which are not used in the method body.

Loading history...
183
		$durationSeconds,
184
		$method
185
	) {
186
		$this->dataFactory->timing(
187
			'wikibase.quality.constraints.check.entity.timing',
188
			$durationSeconds * 1000
189
		);
190
191
		// find the longest limit (and associated log level) that the duration exceeds
192
		list( $limitSeconds, $logLevel ) = $this->findLimit(
193
			$this->constraintCheckOnEntityDurationLimits,
194
			$durationSeconds
195
		);
196
		if ( $limitSeconds === null ) {
197
			return;
198
		}
199
200
		$this->logger->log(
201
			$logLevel,
202
			'Full constraint check on {entityId} ' .
203
			'took longer than {limitSeconds} second(s) ' .
204
			'(duration: {durationSeconds} seconds).',
205
			[
206
				'method' => $method,
207
				'loggingMethod' => __METHOD__,
208
				'durationSeconds' => $durationSeconds,
209
				'limitSeconds' => $limitSeconds,
210
				'entityId' => $entityId->getSerialization(),
211
				// $checkResults currently not logged
212
			]
213
		);
214
	}
215
216
	/**
217
	 * Log a cache hit for a complete constraint check result for the given entity ID.
218
	 *
219
	 * @param EntityId $entityId
220
	 */
221
	public function logCheckConstraintsCacheHit( EntityId $entityId ) {
0 ignored issues
show
Unused Code introduced by
The parameter $entityId is not used and could be removed.

This check looks from parameters that have been defined for a function or method, but which are not used in the method body.

Loading history...
222
		$this->dataFactory->increment(
223
			'wikibase.quality.constraints.cache.entity.hit'
224
		);
225
	}
226
227
	/**
228
	 * Log cache misses for a complete constraint check result for the given entity IDs.
229
	 *
230
	 * @param EntityId[] $entityIds
231
	 */
232
	public function logCheckConstraintsCacheMisses( array $entityIds ) {
233
		$this->dataFactory->updateCount(
234
			'wikibase.quality.constraints.cache.entity.miss',
235
			count( $entityIds )
236
		);
237
	}
238
239
	/**
240
	 * Log that the dependency metadata for a check result had an empty set of entity IDs.
241
	 * This should never happen – at least the entity being checked should always be contained.
242
	 */
243
	public function logEmptyDependencyMetadata() {
244
		$this->logger->log(
245
			'warning',
246
			'Dependency metadata for constraint check result had empty set of entity IDs.',
247
			[
248
				'loggingMethod' => __METHOD__,
249
				// callers of this method don’t have much information to pass to us,
250
				// so for now we don’t log any other structured data
251
				// and hope that the request URL provides enough information
252
			]
253
		);
254
	}
255
256
	/**
257
	 * Log that the dependency metadata for a check result has a very large set of entity IDs.
258
	 *
259
	 * @param EntityId[] $entityIds
260
	 * @param int $maxRevisionIds
261
	 */
262
	public function logHugeDependencyMetadata( array $entityIds, $maxRevisionIds ) {
263
		$this->logger->log(
264
			'warning',
265
			'Dependency metadata for constraint check result has huge set of entity IDs ' .
266
			'(count ' . count( $entityIds ) . ', limit ' . $maxRevisionIds . '); ' .
267
			'caching disabled for this check result.',
268
			[
269
				'loggingMethod' => __METHOD__,
270
				'entityIds' => json_encode(
271
					array_map(
272
						function ( EntityId $entityId ) {
273
							return $entityId->getSerialization();
274
						},
275
						$entityIds
276
					)
277
				),
278
				'maxRevisionIds' => $maxRevisionIds,
279
			]
280
		);
281
	}
282
283
	public function logSparqlHelperTooManyRequestsRetryAfterPresent( ConvertibleTimestamp $retryAfterTime, MWHttpRequest $request ) {
284
		$this->logger->notice(
285
			'Sparql API replied with status 429 and a retry-after header. Requesting to retry after {retryAfterTime}',
286
			[
287
				'retryAfterTime' => $retryAfterTime,
288
				'responseHeaders' => json_encode( $request->getResponseHeaders() ),
289
				'responseContent' => $request->getContent(),
290
			]
291
		);
292
	}
293
294
	public function logSparqlHelperTooManyRequestsRetryAfterInvalid( MWHttpRequest $request ) {
295
		$this->logger->warning(
296
			'Sparql API replied with status 429 and no valid retry-after header.',
297
			[
298
				'responseHeaders' => json_encode( $request->getResponseHeaders() ),
299
				'responseContent' => $request->getContent(),
300
			]
301
		);
302
	}
303
304
}
305